Hi Gerado and Robert, We turned DEBUG on in the application logs and then this weekend I was going to multi-threaded test program to reproduce the issue in a stand-alone program, and when I got the debug logs and stripped out everything except the database queries for the ChangeHistory table, I found some other unexpected transactions which were hitting the ChangeHistory table fairly hard and in rapid succession. At this point development is looking into it, and we believe this application transaction is the source of the issue, which is why I have not responded to your emails. I should know more after tonight. Thanks again for your feedback and responses Regards John -----Original Message----- From: Gerardo Herzig [mailto:gherzig@xxxxxxxxxxx] Sent: Friday, May 13, 2016 4:11 PM To: John Gorman Cc: pgsql-performance@xxxxxxxxxxxxxx Subject: Re: Database transaction with intermittent slow responses Oh, so *all* the transactions are being slowed down at that point...What about CPU IO Wait% at that moment? Could be some other processes stressing the system out? Now im thinking about hard disk issues...maybe some "smart" messages? Have some other hardware to give it a try? Gerardo ----- Mensaje original ----- > De: "John Gorman" <jgorman@xxxxxxxxxxxx> > Para: "Gerardo Herzig" <gherzig@xxxxxxxxxxx> > CC: pgsql-performance@xxxxxxxxxxxxxx, "John Gorman" <jgorman@xxxxxxxxxxxx> > Enviados: Viernes, 13 de Mayo 2016 18:25:37 > Asunto: RE: Database transaction with intermittent slow responses > > 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
