Re: Database transaction with intermittent slow responses - Mailing list pgsql-performance

From Gerardo Herzig
Subject Re: Database transaction with intermittent slow responses
Date
Msg-id 2029525782.1578699.1463181067491.JavaMail.root@fmed.uba.ar
Whole thread Raw
In response to Re: Database transaction with intermittent slow responses  (John Gorman <jgorman@eldocomp.com>)
Responses Re: Database transaction with intermittent slow responses  (Robert Klemme <shortcutter@googlemail.com>)
Re: Database transaction with intermittent slow responses  (John Gorman <jgorman@eldocomp.com>)
List pgsql-performance
Oh, so *all* the transactions are being slowed down at that point...What about CPU IO Wait% at that moment? Could be
someother 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@eldocomp.com>
> Para: "Gerardo Herzig" <gherzig@fmed.uba.ar>
> CC: pgsql-performance@postgresql.org, "John Gorman" <jgorman@eldocomp.com>
> Enviados: Viernes, 13 de Mayo 2016 18:25:37
> Asunto: RE: [PERFORM] 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@fmed.uba.ar]
> Sent: Friday, May 13, 2016 2:05 PM
> To: John Gorman
> Cc: pgsql-performance@postgresql.org
> Subject: Re: [PERFORM] 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@eldocomp.com>
> > Para: pgsql-performance@postgresql.org
> > CC: "John Gorman" <jgorman@eldocomp.com>
> > Enviados: Viernes, 13 de Mayo 2016 16:59:51
> > Asunto: [PERFORM] 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
> >
>
>


pgsql-performance by date:

Previous
From: John Gorman
Date:
Subject: Re: Database transaction with intermittent slow responses
Next
From: Robert Klemme
Date:
Subject: Re: Database transaction with intermittent slow responses