Hi Gerado,
Thanks for the quick response. We do not appear to have a connection limit since our application is the only thing talking to the database, the connections are somewhat limited. We are using about 126 of a max allowed 350 connections. We keep these metrics in a different database, and we also generate alerts if we get close to the catalog/cluster limit.
Also I have been monitoring heavily and watching for locks while the transaction runs for a long time. While I see occasional locks, they are on other tables and are brief, so I do not believe there is a database lock issue/contention.
The application is timing the transaction out. When we detect that the timeout limit has occurred, we cancel the database connection (conn.cancel();) - we have been doing this for several years with no issue.
I setup a adhoc monitor which runs every 2 seconds and displays "select * from pg_stat_activity where datname = 'p306' and current_query not like '<IDLE%'; and then write the output to a log. I can see the transaction being executed in the database for over 50 seconds, so I do believe the database actually is working on it.
We have a few monitoring programs that track and record quite a few thinks including database locks (number and type), connections (number and where). I have reviewed the history and do not see any trends.
If it helps here is a monitor snippet of the transaction taking over 50 seconds (SELECT * FROM ChangeHistory)
>> Wed May 11 07:50:09 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
>> Wed May 11 07:50:11 MST 2016
3709009 | p306 | 15014 | 16387 | p306 | | 172.20.0.82 | coreb | 35859 | 2016-05-11 07:31:31.968087-07 | 2016-05-11 07:50:11.575881-07 | 2016-05-11 07:50:11.766942-07 | f | SELECT * FROM Employee WHERE SocialSecurityNumber BETWEEN $1 AND $2 ORDER BY LastName, FirstName, MiddleName, BlkOfBusID, ClientID, CertificateNumber, SocialSecurityNumber, MedicareID, BirthDate, AlternateID1, AlternateID2 LIMIT 11
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:11.712848-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:11.712887-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:13 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:13.733643-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 16771 | 16387 | p306 | | 172.20.0.82 | coreb | 37470 | 2016-05-11 07:36:18.535139-07 | 2016-05-11 07:50:13.770366-07 | 2016-05-11 07:50:13.811502-07 | f | SELECT * FROM Dependent WHERE DependentID = $1
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:13.733968-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:15 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:15.734777-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:15.73486-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:17 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
>> Wed May 11 07:50:19 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
>> Wed May 11 07:50:21 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 21656 | 16387 | p306 | | 172.20.0.82 | coreb | 41810 | 2016-05-11 07:48:40.95846-07 | 2016-05-11 07:50:21.871077-07 | 2016-05-11 07:50:21.871579-07 | f | DELETE FROM ClaimPrevQueue WHERE Claimnumber = $1
3709009 | p306 | 8042 | 16387 | p306 | | 172.20.0.82 | coreb | 63023 | 2016-05-11 07:14:34.208098-07 | 2016-05-11 07:50:21.813662-07 | 2016-05-11 07:50:21.814575-07 | f | SELECT * FROM Employee WHERE CertificateNumber BETWEEN $1 AND $2 ORDER BY LastName, FirstName, MiddleName, BlkOfBusID, ClientID, CertificateNumber, SocialSecurityNumber, MedicareID, BirthDate, AlternateID1, AlternateID2 LIMIT 11
>> Wed May 11 07:50:23 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:23.85706-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 7925 | 16387 | p306 | | 172.20.0.82 | coreb | 62888 | 2016-05-11 07:14:05.586327-07 | 2016-05-11 07:50:23.517469-07 | 2016-05-11 07:50:23.684134-07 | f | DELETE FROM ToothChartMaintenance WHERE Claimnumber = $1
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:23.857092-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 22235 | 10 | postgres | | | | | 2016-05-11 07:50:22.129887-07 | 2016-05-11 07:50:22.162326-07 | 2016-05-11 07:50:22.162326-07 | f | autovacuum: VACUUM public.adjrespendrsncode
>> Wed May 11 07:50:25 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 7925 | 16387 | p306 | | 172.20.0.82 | coreb | 62888 | 2016-05-11 07:14:05.586327-07 | 2016-05-11 07:50:23.517469-07 | 2016-05-11 07:50:25.931788-07 | f | SELECT * FROM CategoryPlaceService WHERE CategoryID = $1 ORDER BY CategoryID, RangeFrom, RangeTo LIMIT 1000
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:25.920308-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:27 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:27.935677-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:27.938329-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:29 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17652 | 16387 | p306 | | 172.20.0.82 | coreb | 38402 | 2016-05-11 07:39:00.298771-07 | 2016-05-11 07:50:29.615446-07 | 2016-05-11 07:50:29.954405-07 | f | SELECT * FROM Dependent WHERE DepSocialSecurityNumber BETWEEN $1 AND $2 ORDER BY DepCertificateNumber, DepSocialSecurityNumber, DepLastName, DepFirstName, DepMiddleName, DepMedicareID, BirthDate, AlternateID1, AlternateID2 LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:29.966428-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:29.966481-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:31 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:32.000148-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:34 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:33.953492-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:33.953803-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:36 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:35.996862-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:35.996892-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:38 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:38.039441-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:38.036922-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:40 MST 2016
3709009 | p306 | 17321 | 16387 | p306 | | 172.20.0.82 | coreb | 38226 | 2016-05-11 07:38:10.838611-07 | 2016-05-11 07:50:40.059438-07 | 2016-05-11 07:50:40.060951-07 | f | DELETE FROM ClaimPrevQueue WHERE Claimnumber = $1
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 2860 | 16387 | p306 | | 172.20.0.82 | coreb | 56427 | 2016-05-11 06:53:47.633683-07 | 2016-05-11 07:50:40.060863-07 | 2016-05-11 07:50:40.062051-07 | f | SELECT * FROM Employee WHERE CertificateNumber BETWEEN $1 AND $2 ORDER BY LastName, FirstName, MiddleName, BlkOfBusID, ClientID, CertificateNumber, SocialSecurityNumber, MedicareID, BirthDate, AlternateID1, AlternateID2 LIMIT 11
3709009 | p306 | 17652 | 16387 | p306 | | 172.20.0.82 | coreb | 38402 | 2016-05-11 07:39:00.298771-07 | 2016-05-11 07:50:40.059956-07 | 2016-05-11 07:50:40.083659-07 | f | DELETE FROM ToothChartMaintenance WHERE Claimnumber = $1
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:40.077061-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 16771 | 16387 | p306 | | 172.20.0.82 | coreb | 37470 | 2016-05-11 07:36:18.535139-07 | 2016-05-11 07:50:40.060076-07 | 2016-05-11 07:50:40.072735-07 | f | INSERT INTO CrmCallLinks VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20,$21,$22,$23,$24,$25,$26,$27)
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:40.080967-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 18895 | 16387 | p306 | | 172.20.0.82 | coreb | 39389 | 2016-05-11 07:42:04.682022-07 | 2016-05-11 07:50:40.062356-07 | 2016-05-11 07:50:40.062667-07 | f | SELECT * FROM RealtimeTransInfo WHERE SenderID = $1 AND PayLoadID = $2 ORDER BY SenderID DESC, PayLoadID DESC LIMIT 2
3709009 | p306 | 8864 | 16387 | p306 | | 172.20.0.82 | coreb | 64407 | 2016-05-11 07:18:34.848657-07 | 2016-05-11 07:50:39.601078-07 | 2016-05-11 07:50:40.077433-07 | f | SELECT * FROM Facility WHERE FacilityID = $1
>> Wed May 11 07:50:42 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 2860 | 16387 | p306 | | 172.20.0.82 | coreb | 56427 | 2016-05-11 06:53:47.633683-07 | 2016-05-11 07:50:42.094681-07 | 2016-05-11 07:50:42.095179-07 | f | DELETE FROM ClaimPrevQueue WHERE Claimnumber = $1
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:42.023507-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:42.023043-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:44 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:44.054554-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:44.054674-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:46 MST 2016
3709009 | p306 | 17321 | 16387 | p306 | | 172.20.0.82 | coreb | 38226 | 2016-05-11 07:38:10.838611-07 | 2016-05-11 07:50:45.908151-07 | 2016-05-11 07:50:46.08959-07 | f | SELECT * FROM Employee WHERE SocialSecurityNumber BETWEEN $1 AND $2 ORDER BY LastName, FirstName, MiddleName, BlkOfBusID, ClientID, CertificateNumber, SocialSecurityNumber, MedicareID, BirthDate, AlternateID1, AlternateID2 LIMIT 11
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:46.077355-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 16771 | 16387 | p306 | | 172.20.0.82 | coreb | 37470 | 2016-05-11 07:36:18.535139-07 | 2016-05-11 07:50:46.139211-07 | 2016-05-11 07:50:46.141386-07 | f | SELECT * FROM AdjudicationResult WHERE Claimnumber BETWEEN $1 AND $2 ORDER BY Claimnumber DESC LIMIT 11
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:46.067222-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:48 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:48.082695-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:48.082883-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:50 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 2860 | 16387 | p306 | | 172.20.0.82 | coreb | 56427 | 2016-05-11 06:53:47.633683-07 | 2016-05-11 07:50:50.056892-07 | 2016-05-11 07:50:50.174587-07 | f | SELECT * FROM Employee WHERE SocialSecurityNumber BETWEEN $1 AND $2 ORDER BY LastName, FirstName, MiddleName, BlkOfBusID, ClientID, CertificateNumber, SocialSecurityNumber, MedicareID, BirthDate, AlternateID1, AlternateID2 LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:50.107102-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 5620 | 16387 | p306 | TaskRunner | 172.20.0.86 | batchb.eldocomp.com | 37594 | 2016-05-11 07:04:08.129626-07 | 2016-05-11 07:50:49.812093-07 | 2016-05-11 07:50:49.81238-07 | f | SELECT * FROM EDIFtpFileDetails WHERE MsgLogStatus = $1 AND ProcessId > $2 ORDER BY MsgLogStatus, ProcessId LIMIT 10
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:50.107172-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:52 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:52.127455-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:52.127776-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:54 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:54.165381-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:54.165596-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:56 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:56.189515-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:56.176308-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:50:58 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 21656 | 16387 | p306 | | 172.20.0.82 | coreb | 41810 | 2016-05-11 07:48:40.95846-07 | 2016-05-11 07:50:56.785032-07 | 2016-05-11 07:50:56.789767-07 | f | SELECT * FROM FacilityPhysicianAffl WHERE Status IN ('A', 'H', 'D') AND (FacilityID IN (SELECT FacilityID FROM Facility WHERE UPPER(TaxID)= '811190101' AND Status IN ( 'A' , 'H' , 'D') ) AND ( PhysicianID IN (SELECT PhysicianID FROM Physician WHERE Status IN ( 'A' , 'H' , 'D') )) AND (( ISDUMMY='0' AND FacilityID IN ( SELECT FacilityID FROM Facility WHERE FacilityRecordType = 'S' AND ( FacilityName IS NOT NULL AND FacilityName != '' ) ) OR ( FacilityID IN ( SELECT FacilityID FROM Facility WHERE FacilityRecordType = 'F' AND ( FacilityName IS NOT NULL AND FacilityName != '' ) ))))) ORDER BY FacilityID ASC , PhysicianID ASC
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:50:58.212226-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:50:58.269389-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:51:00 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:51:00.228846-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:51:00.229019-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:51:02 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 4715 | 16387 | p306 | TaskRunner | 172.20.0.86 | batchb.eldocomp.com | 33881 | 2016-05-11 07:01:41.247388-07 | 2016-05-11 07:51:02.125906-07 | 2016-05-11 07:51:02.311956-07 | f | SELECT * FROM EmpEligibilityCoverage WHERE EmployeeID = $1 AND EffectiveDate <= $2 ORDER BY EmployeeID DESC, EffectiveDate DESC LIMIT 101
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:51:02.23586-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 16771 | 16387 | p306 | | 172.20.0.82 | coreb | 37470 | 2016-05-11 07:36:18.535139-07 | 2016-05-11 07:51:02.188886-07 | 2016-05-11 07:51:02.295888-07 | f | DELETE FROM ToothChartMaintenance WHERE Claimnumber = $1
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:51:02.235869-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:51:04 MST 2016
3709009 | p306 | 5644 | 16387 | p306 | | 172.20.0.82 | coreb | 59871 | 2016-05-11 07:04:16.503194-07 | 2016-05-11 07:50:09.394202-07 | 2016-05-11 07:50:09.396161-07 | f | SELECT * FROM ChangeHistory WHERE Category BETWEEN $1 AND $2 AND PrimaryKeyOfChange BETWEEN $3 AND $4 ORDER BY ChgTS DESC, ChgUser DESC, Category DESC, PrimaryKeyOfChange DESC LIMIT 11
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:51:04.277287-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:51:04.277543-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:51:06 MST 2016
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:51:06.313649-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:51:06.313855-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
>> Wed May 11 07:51:08 MST 2016
3709009 | p306 | 22530 | 16387 | p306 | | 172.20.0.82 | coreb | 42494 | 2016-05-11 07:51:04.419169-07 | 2016-05-11 07:51:08.351721-07 | 2016-05-11 07:51:08.373929-07 | f | SELECT * FROM ChangeHistory WHERE Category = $1 AND PrimaryKeyOfChange = $2 ORDER BY Category, PrimaryKeyOfChange, ChgTS, ExcludedKeyFields LIMIT 2001
3709009 | p306 | 17312 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 54263 | 2016-05-11 07:38:08.464797-07 | 2016-05-11 07:47:42.982944-07 | 2016-05-11 07:51:08.335854-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
3709009 | p306 | 8671 | 16387 | p306 | | 172.20.0.86 | batchb.eldocomp.com | 55055 | 2016-05-11 07:17:52.292909-07 | 2016-05-11 07:40:50.525528-07 | 2016-05-11 07:51:08.359281-07 | f | SELECT * FROM Employee WHERE EmployeeID BETWEEN $1 AND $2 ORDER BY EmployeeID LIMIT 1001
Regards
John
-----Original Message-----
From: Gerardo Herzig [mailto:gherzig@xxxxxxxxxxx]
Sent: Friday, May 13, 2016 2:05 PM
To: John Gorman
Cc: pgsql-performance@xxxxxxxxxxxxxx
Subject: Re: Database transaction with intermittent slow responses
After quick reading, im thinking about a couples of chances:
1) You are hitting a connection_limit
2) You are hitting a lock contention (perhaps some other backend is locking the table and not releasing it)
Who throws the timeout? It is Postgres or your JDBC connector?
My initial blind guess is that your "timed out queries" never gets postgres at all, and are blocked prior to that for some other issue. If im wrong, well, you should at least have the timeout recorded in your logs.
You should also track #of_connectinos and #of_locks over that tables.
See http://www.postgresql.org/docs/9.1/static/view-pg-locks.html for pg_lock information
That should be my starting point for viewing whats going on.
HTH
Gerardo
----- Mensaje original -----
> De: "John Gorman" <jgorman@xxxxxxxxxxxx>
> Para: pgsql-performance@xxxxxxxxxxxxxx
> CC: "John Gorman" <jgorman@xxxxxxxxxxxx>
> Enviados: Viernes, 13 de Mayo 2016 16:59:51
> Asunto: Database transaction with intermittent slow responses
>
>
> Transactions to table, ChangeHistory, have recently become
> intermittently slow and is increasing becoming slower.
>
> * No database configuration changes have been made recently
> * We have run vacuum analyze
> * We have tried backing up and reloading the table (data, indexes,
> etc)
>
> Some transactions respond quickly (200 ms) and others take over 55
> seconds (we cancel the query after 55 seconds – our timeout SLA).
> The problem has recently become very bad. It is the same query being
> issued but with different parameters.
>
> If the transaction takes over 55 seconds and I run the query manually
> (with or without EXPLAIN ANALYZE) it returns quickly (a few hundred
> ms). In case I am looking at cache, I have a list of other queries
> (just different parameters) that have timed out and when I run them
> (without the limit even) the response is very timely.
>
> Any help or insight would be great.
>
> NOTE: our application is connecting to the database via JDBC and we
> are using PreparedStatements. I have provided full details so all
> information is available, but please let me know if any other
> information is needed – thx in advance.
>
> p306=> EXPLAIN ANALYZE SELECT * FROM ChangeHistory WHERE Category
> BETWEEN 'Employee' AND 'Employeezz' AND PrimaryKeyOfChange BETWEEN
> '312313' AND '312313!zz' ORDER BY ChgTS DESC, ChgUser DESC, Category
> DESC, PrimaryKeyOfChange DESC LIMIT 11;
> QUERY PLAN
> ------------------------------------------------------------------------------------------------------
> Limit (cost=33.66..33.67 rows=1 width=136) (actual time=0.297..0.297
> rows=11 loops=1)
> -> Sort (cost=33.66..33.67 rows=1 width=136) (actual
> time=0.297..0.297 rows=11 loops=1)
> Sort Key: chgts, chguser, category, primarykeyofchange
> Sort Method: top-N heapsort Memory: 27kB
> -> Index Scan using changehistory_idx4 on changehistory
> (cost=0.00..33.65 rows=1 width=136) (actual time=0.046..
> 0.239 rows=85 loops=1)
> Index Cond: (((primarykeyofchange)::text >= '312313'::text) AND
> ((primarykeyofchange)::text <= '312313!zz'::
> text))
> Filter: (((category)::text >= 'Employee'::text) AND ((category)::text
> <= 'Employeezz'::text))
> Total runtime: 0.328 ms
> (8 rows)
>
> >>>
> History this week of counts with good response times vs timeouts.
>
> | Date | Success # | Time Out # | Avg. Success Secs |
> |------------+-----------+------------+-------------------|
> | 2016-05-09 | 18 | 31 | 7.9 |
> | 2016-05-10 | 17 | 25 | 10.5 |
> | 2016-05-11 | 27 | 33 | 10.1 |
> | 2016-05-12 | 68 | 24 | 9.9 |
>
>
> >>> Sample transaction response times
>
> | Timestamp | Tran ID | Resp MS | Resp CD
> --------------------+----------------+---------+--------
> 2016-05-10 06:20:19 | ListChangeHist | 55,023 | TIMEOUT
> 2016-05-10 07:47:34 | ListChangeHist | 55,017 | TIMEOUT
> 2016-05-10 07:48:00 | ListChangeHist | 9,866 | OK
> 2016-05-10 07:48:10 | ListChangeHist | 2,327 | OK
> 2016-05-10 07:59:23 | ListChangeHist | 55,020 | TIMEOUT
> 2016-05-10 08:11:20 | ListChangeHist | 55,030 | TIMEOUT
> 2016-05-10 08:31:45 | ListChangeHist | 4,216 | OK
> 2016-05-10 08:35:09 | ListChangeHist | 7,898 | OK
> 2016-05-10 08:36:18 | ListChangeHist | 9,810 | OK
> 2016-05-10 08:36:56 | ListChangeHist | 55,027 | TIMEOUT
> 2016-05-10 08:37:33 | ListChangeHist | 46,433 | OK
> 2016-05-10 08:38:09 | ListChangeHist | 55,019 | TIMEOUT
> 2016-05-10 08:53:43 | ListChangeHist | 55,019 | TIMEOUT
> 2016-05-10 09:45:09 | ListChangeHist | 55,022 | TIMEOUT
> 2016-05-10 09:46:13 | ListChangeHist | 55,017 | TIMEOUT
> 2016-05-10 09:49:27 | ListChangeHist | 55,011 | TIMEOUT
> 2016-05-10 09:52:12 | ListChangeHist | 55,018 | TIMEOUT
> 2016-05-10 09:57:42 | ListChangeHist | 9,462 | OK
> 2016-05-10 10:05:21 | ListChangeHist | 55,016 | TIMEOUT
> 2016-05-10 10:05:29 | ListChangeHist | 136 | OK
> 2016-05-10 10:05:38 | ListChangeHist | 1,517 | OK
>
> Artifacts
> ======================
>
> $ >uname -a
> SunOS ***** 5.10 Generic_150400-30 sun4v sparc sun4v
>
> Memory : 254G phys mem, 207G free mem.
> Processors: 32 - CPU is mostly 80% free
>
> >>>
> p306=> select version();
> version
> ---------------------------------------------------------------------------------------------------
> PostgreSQL 9.1.14 on sparc-sun-solaris2.10, compiled by gcc (GCC)
> 3.4.3 (csl-sol210-3_4-branch+sol_rpath), 64-bit
>
> >>>
> p306=> \dt+ changehistory
> List of relations
> Schema | Name | Type | Owner | Size | Description
> --------+---------------+-------+-------+-------+-------------
> public | changehistory | table | p306 | 17 GB |
>
> >>>
> p306=> \di+ changehistory*
> List of relations
> Schema | Name | Type | Owner | Table | Size | Description
> --------+-----------------------+-------+-------+---------------+---------+-------------
> public | changehistory_idx1 | index | p306 | changehistory | 9597 MB
> |
> public | changehistory_idx3 | index | p306 | changehistory | 11 GB |
> public | changehistory_idx4 | index | p306 | changehistory | 4973 MB
> |
> public | changehistory_pkey | index | p306 | changehistory | 2791 MB
> |
> public | changehistory_search2 | index | p306 | changehistory | 9888
> MB |
> public | changehistory_search3 | index | p306 | changehistory | 10 GB
> |
> public | changehistory_search4 | index | p306 | changehistory | 9240
> MB |
> public | changehistory_search5 | index | p306 | changehistory | 8373
> MB |
> (8 rows)
>
>
> >>>
> p306=> select count(*) from changehistory ;
> count
> ------------
> 129,185,024
>
> >>>
> Show all (filtered)
> ======================================================
>
> name | setting
> ---------------------------------+--------------------
> autovacuum | on
> autovacuum_analyze_scale_factor | 0.001
> autovacuum_analyze_threshold | 500
> autovacuum_freeze_max_age | 200000000
> autovacuum_max_workers | 5
> autovacuum_naptime | 1min
> autovacuum_vacuum_cost_delay | 0
> autovacuum_vacuum_cost_limit | -1
> autovacuum_vacuum_scale_factor | 0.001
> autovacuum_vacuum_threshold | 500
> bgwriter_delay | 200ms
> block_size | 8192
> check_function_bodies | on
> checkpoint_completion_target | 0.9
> checkpoint_segments | 256
> checkpoint_timeout | 1h
> checkpoint_warning | 30s
> client_encoding | UTF8
> commit_delay | 0
> commit_siblings | 5
> cpu_index_tuple_cost | 0.005
> cpu_operator_cost | 0.0025
> cpu_tuple_cost | 0.01
> cursor_tuple_fraction | 0.1
> deadlock_timeout | 1s
> default_statistics_target | 100
> default_transaction_deferrable | off
> default_transaction_isolation | read committed
> default_transaction_read_only | off
> default_with_oids | off
> effective_cache_size | 8GB
> from_collapse_limit | 8
> fsync | on
> full_page_writes | on
> ignore_system_indexes | off
> join_collapse_limit | 8
> krb_caseins_users | off
> lo_compat_privileges | off
> maintenance_work_mem | 1GB
> max_connections | 350
> max_files_per_process | 1000
> max_function_args | 100
> max_identifier_length | 63
> max_index_keys | 32
> max_locks_per_transaction | 64
> max_pred_locks_per_transaction | 64
> max_prepared_transactions | 0
> max_stack_depth | 2MB
> max_wal_senders | 5
> random_page_cost | 4
> segment_size | 1GB
> seq_page_cost | 1
> server_encoding | UTF8
> server_version | 9.1.14
> shared_buffers | 2GB
> sql_inheritance | on
> statement_timeout | 0
> synchronize_seqscans | on
> synchronous_commit | on
> synchronous_standby_names |
> tcp_keepalives_count | 0
> tcp_keepalives_idle | -1
> tcp_keepalives_interval | 0
> track_activities | on
> track_activity_query_size | 1024
> track_counts | on
> track_functions | none
> transaction_deferrable | off
> transaction_isolation | read committed
> transaction_read_only | off
> transform_null_equals | off
> update_process_title | on
> vacuum_cost_delay | 0
> vacuum_cost_limit | 200
> vacuum_cost_page_dirty | 20
> vacuum_cost_page_hit | 1
> vacuum_cost_page_miss | 10
> vacuum_defer_cleanup_age | 0
> vacuum_freeze_min_age | 50000000
> vacuum_freeze_table_age | 150000000
>
--
Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
