Long Running Commits - Mailing list pgsql-performance
| From | Brad Nicholson |
|---|---|
| Subject | Long Running Commits |
| Date | |
| Msg-id | 1236183530.21727.82.camel@bnicholson-desktop Whole thread Raw |
| List | pgsql-performance |
Running PG 8.1.11 on AIX 5.3 Trying to track down the cause of long running commits on one of our DB servers. I can rule checkpoints out (I've set log_min_messages to debug2 and the commits are not happening during checkpoints). We have this problem over a period of ~ 35 minutes per day only. during that period we have no change in our write load,but we do have substantial increase in reads on one table (pretty much all being served by index scans from the buffer pool - which most likely pointsto a shift in activity over the time period, and not the problem itself). Over the same time, we also see an abnormally large number of connections being opened and closed. We can see this in theDB connection pool logs as well as the DB logs). This is most likely being driven by the activity shift that we can see in the stats. What we do see is connections being opened and closed rapidly during this same period of time (DB logs below). I'm wonderingif the commits are waiting on something at the file system level due to the processes. Ulimit settings on the server: ulimit -a core file size (blocks, -c) soft data seg size (kbytes, -d) soft file size (blocks, -f) unlimited max memory size (kbytes, -m) hard open files (-n) 4096 pipe size (512 bytes, -p) 64 stack size (kbytes, -s) soft cpu time (seconds, -t) unlimited max user processes (-u) 10240 virtual memory (kbytes, -v) unlimited DB logs: 2009-03-04 09:56:13.465 CUT [561402] DEBUG: forked new backend, pid=794696 socket=9 2009-03-04 09:56:13.645 CUT [561402] DEBUG: forked new backend, pid=2101474 socket=9 2009-03-04 09:56:13.645 CUT [561402] DEBUG: server process (PID 516334) exited with exit code 0 2009-03-04 09:56:13.646 CUT [561402] DEBUG: server process (PID 1458332) exited with exit code 0 2009-03-04 09:56:13.646 CUT [561402] DEBUG: server process (PID 2174998) exited with exit code 0 2009-03-04 09:56:13.647 CUT [561402] DEBUG: server process (PID 1519662) exited with exit code 0 2009-03-04 09:56:13.647 CUT [561402] DEBUG: server process (PID 1646618) exited with exit code 0 2009-03-04 09:56:13.647 CUT [561402] DEBUG: server process (PID 999648) exited with exit code 0 2009-03-04 09:56:13.648 CUT [561402] DEBUG: server process (PID 2285774) exited with exit code 0 2009-03-04 09:56:13.648 CUT [561402] DEBUG: server process (PID 1622108) exited with exit code 0 2009-03-04 09:56:13.648 CUT [561402] DEBUG: server process (PID 1024216) exited with exit code 0 2009-03-04 09:56:13.649 CUT [561402] DEBUG: server process (PID 1392706) exited with exit code 0 2009-03-04 09:56:13.665 CUT [561402] DEBUG: forked new backend, pid=1392708 socket=9 2009-03-04 09:56:13.666 CUT [561402] DEBUG: server process (PID 1773680) exited with exit code 0 2009-03-04 09:56:13.669 CUT [561402] DEBUG: forked new backend, pid=1773682 socket=9 2009-03-04 09:56:13.805 CUT [561402] DEBUG: forked new backend, pid=1024218 socket=9 2009-03-04 09:56:13.805 CUT [561402] DEBUG: server process (PID 1589374) exited with exit code 0 2009-03-04 09:56:13.806 CUT [561402] DEBUG: server process (PID 995536) exited with exit code 0 2009-03-04 09:56:13.806 CUT [561402] DEBUG: server process (PID 688336) exited with exit code 0 2009-03-04 09:56:13.806 CUT [561402] DEBUG: server process (PID 2035798) exited with exit code 0 2009-03-04 09:56:13.807 CUT [561402] DEBUG: server process (PID 1429700) exited with exit code 0 2009-03-04 09:56:13.807 CUT [561402] DEBUG: server process (PID 2043960) exited with exit code 0 2009-03-04 09:56:13.807 CUT [561402] DEBUG: server process (PID 2158782) exited with exit code 0 2009-03-04 09:56:13.808 CUT [561402] DEBUG: server process (PID 2306144) exited with exit code 0 2009-03-04 09:56:13.808 CUT [561402] DEBUG: server process (PID 884978) exited with exit code 0 2009-03-04 09:56:13.808 CUT [561402] DEBUG: server process (PID 1781930) exited with exit code 0 2009-03-04 09:56:13.809 CUT [561402] DEBUG: server process (PID 2277572) exited with exit code 0 2009-03-04 09:56:13.809 CUT [561402] DEBUG: server process (PID 663656) exited with exit code 0 2009-03-04 09:56:13.809 CUT [561402] DEBUG: server process (PID 2343006) exited with exit code 0 2009-03-04 09:56:13.810 CUT [561402] DEBUG: server process (PID 889026) exited with exit code 0 2009-03-04 09:56:13.810 CUT [561402] DEBUG: server process (PID 2404546) exited with exit code 0 2009-03-04 09:56:13.810 CUT [561402] DEBUG: server process (PID 581830) exited with exit code 0 2009-03-04 09:56:13.811 CUT [561402] DEBUG: server process (PID 1433846) exited with exit code 0 2009-03-04 09:56:13.811 CUT [561402] DEBUG: server process (PID 667690) exited with exit code 0 2009-03-04 09:56:13.932 CUT [561402] DEBUG: forked new backend, pid=667692 socket=9 2009-03-04 09:56:13.933 CUT [561402] DEBUG: server process (PID 864402) exited with exit code 0 2009-03-04 09:56:13.933 CUT [561402] DEBUG: server process (PID 594124) exited with exit code 0 2009-03-04 09:56:13.934 CUT [561402] DEBUG: server process (PID 852202) exited with exit code 0 2009-03-04 09:56:13.935 CUT [561402] DEBUG: server process (PID 2433156) exited with exit code 0 2009-03-04 09:56:13.935 CUT [561402] DEBUG: server process (PID 2216120) exited with exit code 0 2009-03-04 09:56:13.936 CUT [561402] DEBUG: server process (PID 1761484) exited with exit code 0 2009-03-04 09:56:13.936 CUT [561402] DEBUG: server process (PID 815268) exited with exit code 0 2009-03-04 09:56:13.936 CUT [561402] DEBUG: server process (PID 876668) exited with exit code 0 2009-03-04 09:56:13.937 CUT [561402] DEBUG: server process (PID 897060) exited with exit code 0 2009-03-04 09:56:13.937 CUT [561402] DEBUG: server process (PID 2199742) exited with exit code 0 2009-03-04 09:56:13.937 CUT [561402] DEBUG: server process (PID 913618) exited with exit code 0 2009-03-04 09:56:13.937 CUT [561402] DEBUG: server process (PID 2334774) exited with exit code 0 2009-03-04 09:56:13.984 CUT [561402] DEBUG: forked new backend, pid=2334776 socket=9 2009-03-04 09:56:14.065 CUT [602282] appdb appuser 1.2.3.3 LOG: duration: 872.457 ms statement: EXECUTE <unnamed> [PREPARE: commit] 2009-03-04 09:56:14.065 CUT [868552] appdb appuser 1.2.3.4 LOG: duration: 873.756 ms statement: EXECUTE <unnamed> [PREPARE: commit] 2009-03-04 09:56:14.075 CUT [2212000] appdb appuser 1.2.3.5 LOG: duration: 586.276 ms statement: EXECUTE <unnamed> [PREPARE: commit] 2009-03-04 09:56:14.076 CUT [561402] DEBUG: forked new backend, pid=913620 socket=9 2009-03-04 09:56:14.095 CUT [561402] DEBUG: forked new backend, pid=782510 socket=9 2009-03-04 09:56:14.106 CUT [561402] DEBUG: forked new backend, pid=2285776 socket=9 2009-03-04 09:56:14.179 CUT [561402] DEBUG: forked new backend, pid=999650 socket=9 2009-03-04 09:56:14.194 CUT [561402] DEBUG: forked new backend, pid=1646620 socket=9 2009-03-04 09:56:14.245 CUT [561402] DEBUG: forked new backend, pid=921634 socket=9 2009-03-04 09:56:14.255 CUT [561402] DEBUG: forked new backend, pid=1257600 socket=9 2009-03-04 09:56:14.265 CUT [561402] DEBUG: forked new backend, pid=1622114 socket=9 2009-03-04 09:56:14.325 CUT [561402] DEBUG: forked new backend, pid=1519664 socket=9 2009-03-04 09:56:14.326 CUT [561402] DEBUG: forked new backend, pid=1839238 socket=9 2009-03-04 09:56:14.335 CUT [561402] DEBUG: forked new backend, pid=2412680 socket=9 2009-03-04 09:56:14.425 CUT [561402] DEBUG: forked new backend, pid=2007238 socket=9 2009-03-04 09:56:14.426 CUT [561402] DEBUG: server process (PID 2363424) exited with exit code 0 2009-03-04 09:56:14.426 CUT [561402] DEBUG: server process (PID 1749056) exited with exit code 0 2009-03-04 09:56:14.426 CUT [561402] DEBUG: server process (PID 2056242) exited with exit code 0 2009-03-04 09:56:14.427 CUT [561402] DEBUG: server process (PID 770156) exited with exit code 0 2009-03-04 09:56:14.433 CUT [561402] DEBUG: forked new backend, pid=770158 socket=9 2009-03-04 09:56:14.433 CUT [561402] DEBUG: server process (PID 2379944) exited with exit code 0 2009-03-04 09:56:14.484 CUT [561402] DEBUG: forked new backend, pid=2379946 socket=9 2009-03-04 09:56:14.485 CUT [561402] DEBUG: server process (PID 1130616) exited with exit code 0 2009-03-04 09:56:14.494 CUT [561402] DEBUG: forked new backend, pid=1130618 socket=9 2009-03-04 09:56:14.505 CUT [561402] DEBUG: forked new backend, pid=516338 socket=9 2009-03-04 09:56:14.506 CUT [561402] DEBUG: forked new backend, pid=2199744 socket=9 -- Brad Nicholson 416-673-4106 Database Administrator, Afilias Canada Corp.
pgsql-performance by date: