Page 1 of 2 12 LastLast
Results 1 to 15 of 21
  1. #1
    Join Date
    Jul 2009
    Posts
    14

    Unanswered: how to know which query is responsible for slow and 100% during several seconds ?

    hi !

    i'm incharge of maintenance of a postgresql 8.1 server where an ERP is in prod.

    Several operations make a load 100% cpu usage with only 1.5% of RAM in use.

    where is the problem ?
    i can redo the problem as i want but cannot look in the ERP to see which queries need 100%.

    i'd like to optimize the balance like 70% cpu and 30% of RAM.

    is it possible ?

  2. #2
    Join Date
    Nov 2006
    Posts
    82
    Several operations make a load 100% cpu usage with only 1.5% of RAM in use.

    where is the problem ?
    How long cpu usage is 100%

    i'd like to optimize the balance like 70% cpu and 30% of RAM.
    Why do you want that?

  3. #3
    Join Date
    Mar 2011
    Posts
    27
    Quote Originally Posted by Michael REMY View Post
    hi !

    i'm incharge of maintenance of a postgresql 8.1 server where an ERP is in prod.

    Several operations make a load 100% cpu usage with only 1.5% of RAM in use.

    where is the problem ?
    i can redo the problem as i want but cannot look in the ERP to see which queries need 100%.

    i'd like to optimize the balance like 70% cpu and 30% of RAM.

    is it possible ?
    Set the parameter log_min_duration_statement to 1000 or smaller, which will log every query that takes more than that number of milliseconds. Then scan your log file to pick out the slow statements. However, if the problem is a bunch of fast queries it is more difficult to catch.

    Alternatively: you say you can reproduce the problem - do it in an isolated environment with log_min_duration_statement set to 0 which will log EVERY query run against the database.

  4. #4
    Join Date
    Jul 2009
    Posts
    14

    Lightbulb long query found !

    thanks

    i had done what you adviced me and, i found in the log a long query. i will check how to optimize hit.
    for the information, the long query is :

    2011-07-18 12:17:10 CEST LOG: 15150.361 ms instruction : select id from sale_order_line where (state in ('confirmed','confirmed_wait','manquant')) and (id in (27403,27405,27399, XXXXXXXX)) order by id DESC limit 50
    and there are almost 10pages of IDs listed in place of XXXX i quote !!!!!
    is there any a way to know if the problem came
    - from the order statement of the query
    - or from the number of value included in the sub state IN

    in this query, there is two AND statement :
    -first S1 : state in ('confirmed','confirmed_wait','manquant'))
    -second S2 : id in (27403,27405,27399, XXXXXXXX)

    does the order of S1 and S2 can impact the speed ?

    does replacing state in A,B,C by samething else can increase the speed ?

  5. #5
    Join Date
    Nov 2006
    Posts
    82
    Quote Originally Posted by Michael REMY View Post
    thanks

    i had done what you adviced me and, i found in the log a long query. i will check how to optimize hit.
    for the information, the long query is :



    and there are almost 10pages of IDs listed in place of XXXX i quote !!!!!
    is there any a way to know if the problem came
    - from the order statement of the query
    - or from the number of value included in the sub state IN

    in this query, there is two AND statement :
    -first S1 : state in ('confirmed','confirmed_wait','manquant'))
    -second S2 : id in (27403,27405,27399, XXXXXXXX)

    does the order of S1 and S2 can impact the speed ?

    does replacing state in A,B,C by samething else can increase the speed ?
    Check the execution plan for this query
    Code:
    explain <you select query>
    and post here.
    Usually ORDER BY statements are rather 'time-consuming'

  6. #6
    Join Date
    Jul 2009
    Posts
    14

    Unhappy

    here the plan (got using pgadmin) :

    [pre]
    "Limit (cost=0.00..26675.74 rows=50 width=4) (actual time=3.982..264.556 rows=50 loops=1)"
    " -> Index Scan Backward using sale_order_line_pkey on sale_order_line (cost=0.00..1202542.36 rows=2254 width=4) (actual time=3.977..264.454 rows=50 loops=1)"
    " Filter: ((((state)::text = 'confirmed'::text) OR ((state)::text = 'confirmed_wait'::text) OR ((state)::text = 'manquant'::text)) AND ((id = 27403) OR (id = 27405) OR (id = 27399) OR (id = 16583) OR (id = 27395) OR (id = 19018) OR (id = 27394) OR (i (..)"
    "Total runtime: 309.079 ms"
    [/pre]

    don't you think the real problem is the number of statement of the form
    OR (id = 27399)
    because there are at least 25000 ! Thrust me, the whole query took 10-20pages of copy-paste from the linux console !

    or maybe it is the "((((state)::text = 'confirmed'::text) OR ((state)::text = 'confirmed_wait'::text) OR ((state)::text = 'manquant'::text))" but i already have an index on this column. And already vaccum, and eindex the table.. : no gain time !

  7. #7
    Join Date
    Mar 2011
    Posts
    27
    Quote Originally Posted by Michael REMY View Post
    here the plan (got using pgadmin) :

    [pre]
    "Limit (cost=0.00..26675.74 rows=50 width=4) (actual time=3.982..264.556 rows=50 loops=1)"
    " -> Index Scan Backward using sale_order_line_pkey on sale_order_line (cost=0.00..1202542.36 rows=2254 width=4) (actual time=3.977..264.454 rows=50 loops=1)"
    " Filter: ((((state)::text = 'confirmed'::text) OR ((state)::text = 'confirmed_wait'::text) OR ((state)::text = 'manquant'::text)) AND ((id = 27403) OR (id = 27405) OR (id = 27399) OR (id = 16583) OR (id = 27395) OR (id = 19018) OR (id = 27394) OR (i (..)"
    "Total runtime: 309.079 ms"
    [/pre]

    don't you think the real problem is the number of statement of the form

    because there are at least 25000 ! Thrust me, the whole query took 10-20pages of copy-paste from the linux console !

    or maybe it is the "((((state)::text = 'confirmed'::text) OR ((state)::text = 'confirmed_wait'::text) OR ((state)::text = 'manquant'::text))" but i already have an index on this column. And already vaccum, and eindex the table.. : no gain time !

    I would assume hitting 25000 index pages is the problem. It is probably faster to do a sequential scan on the table, but I don't know how big it is. It is not a good idea to have such big IN lists though, better to use a subquery or CTE to return the data. Do you have accurate stats on the table? When was the last time it was analyzed:

    select last_analyze, last_autoanalyze from pg_stat_all_tables where relname = 'sale_order_line';

  8. #8
    Join Date
    Jul 2009
    Posts
    14

    Post no such field

    there is no such field last_analyze, last_autoanalyze in my pg_stat_all_tables.
    (maybe only in >8.1)

    here what i get with select * (i round the value) :
    relid: 220000
    seq_scan : 800
    seq_tup_read : 15 000 000
    idx_scan : 7718298
    idx_tup_fetch : 7956569
    ,_tup_ins : 2046
    n_tup_upd : 42233
    n_tup_del : 213

    i hope it could help...

  9. #9
    Join Date
    Mar 2011
    Posts
    27
    Quote Originally Posted by Michael REMY View Post
    there is no such field last_analyze, last_autoanalyze in my pg_stat_all_tables.
    (maybe only in >8.1)

    here what i get with select * (i round the value) :
    relid: 220000
    seq_scan : 800
    seq_tup_read : 15 000 000
    idx_scan : 7718298
    idx_tup_fetch : 7956569
    ,_tup_ins : 2046
    n_tup_upd : 42233
    n_tup_del : 213

    i hope it could help...

    Oh right... 8.1. This might be a good excuse to get approval for a 9.0 upgrade

    Try running this in your session just before an explain analyze to force a seq scan instead of an index scan and see how that changes things:

    set random_page_cost = 10;

    If it doesn't switch to a seq scan, keep increasing the number until it does!

  10. #10
    Join Date
    Jul 2009
    Posts
    14

    Unhappy doesn't work

    hi

    i test your advice :
    passing #random_page_cost=4 to a value of 10 then 20 then 30 then 40 (and un-comment!)
    but i got no time gain !
    each time i stop,start or reload postgresql81
    not gain !

    i just copy-paste the full query into a text file, the file size is 107KB ! it is huge for a query isn't it ?

    is there any postgresql parameter which can improve the systm for long-weight query (but simple query).
    my query is not complicated at all, just long with many conditions.

    what i don't understand is why postgres don't use more memory (always<5%) for execute this query. Many more RAM instead disk access should really improve it.?

  11. #11
    Join Date
    Mar 2011
    Posts
    27
    Quote Originally Posted by Michael REMY View Post
    i test your advice :
    passing #random_page_cost=4 to a value of 10 then 20 then 30 then 40 (and un-comment!)
    but i got no time gain !
    each time i stop,start or reload postgresql81
    not gain !
    I wanted to see if the explain analyze output changed to using a seq scan instead of an index scan, and what impacts that had.

    Quote Originally Posted by Michael REMY View Post
    i just copy-paste the full query into a text file, the file size is 107KB ! it is huge for a query isn't it ?
    It is definitely big, but I've seen bigger For example the query in this post was about 300KB.

    Quote Originally Posted by Michael REMY View Post
    is there any postgresql parameter which can improve the systm for long-weight query (but simple query).
    my query is not complicated at all, just long with many conditions.

    what i don't understand is why postgres don't use more memory (always<5%) for execute this query. Many more RAM instead disk access should really improve it.?
    Where are you getting the 5% figure from? It uses the OS file system cache as well as the shared_buffers parameter for caching disk reads.

    Also, I just noticed the runtime in one of your previous comments at 309ms - is that correct? If so, that is very fast for a query like this!

  12. #12
    Join Date
    Jul 2009
    Posts
    14
    the runtime is around 15,6s on a bi-xeon at 2Ghz and around 7s in a VM with core i7-975 (3.33ghz)

    i get the 5-6% memory used by the command line 'top'

  13. #13
    Join Date
    Jul 2009
    Posts
    14

    Unhappy

    more information i just discover :

    the database takes in fact 800Mb (and 30mb in the compressed dump), so it is big ?
    the table size of my query takes around 20Mb (index includes)

  14. #14
    Join Date
    Mar 2011
    Posts
    27
    800mb is tiny. What are your settings for :
    shared_buffers
    effective_cache_size

    And how much memory is on your server?

  15. #15
    Join Date
    Jul 2009
    Posts
    14
    thank for your help,

    so

    Quote Originally Posted by someidiot View Post
    800mb is tiny. What are your settings for :
    shared_buffers
    effective_cache_size

    And how much memory is on your server?
    The server have 2GB of memory
    shared_buffers=5000
    temp_buffers=4000
    effective_cache_size=16000
    work_memory=12288
    max_connection=125

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •