Jira (PDB-5550) Long queries cause Postgresql gone into maintenance mode

10 views
Skip to first unread message

Alvin Rodis (Jira)

unread,
Oct 12, 2022, 4:07:01 AM10/12/22
to puppe...@googlegroups.com
Alvin Rodis updated an issue
 
PuppetDB / Improvement PDB-5550
Long queries cause Postgresql gone into maintenance mode
Change By: Alvin Rodis
Zendesk Ticket Count: 1
Zendesk Ticket IDs: 49787
Add Comment Add Comment
 
This message was sent by Atlassian Jira (v8.20.11#820011-sha1:0629dd8)
Atlassian logo

Alvin Rodis (Jira)

unread,
Oct 12, 2022, 4:07:03 AM10/12/22
to puppe...@googlegroups.com
Xiuqing Jiang created an issue
Issue Type: Improvement Improvement
Assignee: Unassigned
Created: 2022/10/12 1:06 AM
Priority: Normal Normal
Reporter: Xiuqing Jiang

There were a lot of multi-day queries stuck in Postgres which cause Postgreql gone into maintenance mode.

Like for pid 18987:

16398 | pe-puppetdb | 18987 | 16387 | pe-puppetdb | PostgreSQL JDBC Driver | 10.0.168.34 | | 58688 | 2022-10-12 01:01:40.424688+00 | 2022-10-12 01:22:43.228219+00 | 2022-10-12 01:22:43.228888+00 | 2022-10-12 01:22:43.228952+00 | Client | ClientRead | idle in transaction | 17902765 | 17896313 | insert into certnames (certname) values ($1) on conflict (certname) do update set deactivated=null, expired=null where (certnames.deactivated < $2 or certnames.expired < $3)

2022-10-06 23:40:32.795 UTC [db:pe-puppetdb,sess:633f59a0.4a2b,pid:18987,vtid:131/16035,tid:11303402] LOG: process 18987 still waiting for ShareLock on transaction 11303387 after 1000.085 ms
2022-10-06 23:40:32.840 UTC [db:pe-puppetdb,sess:633f59a0.4a2b,pid:18987,vtid:131/16035,tid:11303402] LOG: process 18987 acquired ShareLock on transaction 11303387 after 1045.411 ms

2022-10-12 01:02:49.273 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11320,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17880045 after 1000.109 ms
2022-10-12 01:02:53.733 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11320,tid:0] LOG: process 18987 acquired ShareLock on transaction 17880045 after 5459.988 ms
2022-10-12 01:04:55.270 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11383,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17881345 after 1000.071 ms
2022-10-12 01:04:58.734 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11383,tid:0] LOG: process 18987 acquired ShareLock on transaction 17881345 after 4464.075 ms
2022-10-12 01:06:40.901 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11442,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17882875 after 1000.073 ms
2022-10-12 01:07:22.328 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11442,tid:0] LOG: process 18987 acquired ShareLock on transaction 17882875 after 42427.311 ms
2022-10-12 01:08:33.497 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11553,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17884491 after 1000.185 ms
2022-10-12 01:08:36.558 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11553,tid:0] LOG: process 18987 acquired ShareLock on transaction 17884491 after 4061.484 ms
2022-10-12 01:10:34.212 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11612,tid:0] LOG: process 18987 still waiting for RowExclusiveLock on relation 17473 of database 16398 after 1000.052 ms at character 13
2022-10-12 01:10:39.878 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11612,tid:0] LOG: process 18987 acquired RowExclusiveLock on relation 17473 of database 16398 after 6665.157 ms at character 13
2022-10-12 01:20:29.989 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11950,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17898305 after 1000.116 ms
2022-10-12 01:20:41.309 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11950,tid:0] LOG: process 18987 acquired ShareLock on transaction 17898305 after 12320.454 ms

* Please see Zendesk Support tab for further comments and attachments.

Alvin Rodis (Jira)

unread,
Oct 12, 2022, 4:07:03 AM10/12/22
to puppe...@googlegroups.com
Alvin Rodis updated an issue
Change By: Alvin Rodis
Labels: jira_escalated

Xiuqing Jiang (Jira)

unread,
Oct 12, 2022, 4:14:03 AM10/12/22
to puppe...@googlegroups.com
Xiuqing Jiang updated an issue
Change By: Xiuqing Jiang
There Customer Splunk reported that there were a lot of multi-day queries stuck in Postgres which cause Postgreql gone into maintenance mode.
Like for pid 18987:


{{}}
{code:java}
datid | datname | pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | query_start | state_change | wait_event_type | wait_event | state | backend_xid | backend_xmin |
16398 | pe-puppetdb | 18987 |    16387 | pe-puppetdb      | PostgreSQL JDBC Driver | 10.0.168.34  |                 |       58688 | 2022-10-12 01:01:40.424688+00 | 2022-10-12 01:22:43.228219+00 | 2022-10-12 01:22:43.228888+00 | 2022-10-12 01:22:43.228952+00 | Client          | ClientRead          | idle in transaction |    17902765 |     17896313 | insert into certnames (certname) values ($1)  on conflict (certname) do update set deactivated=null, expired=null  where (certnames.deactivated < $2 or certnames.expired < $3)
{code}
 

 

 
{code:java}
2022-10-06 23:40:32.795 UTC [db:pe-puppetdb,sess:633f59a0.4a2b,pid:18987,vtid:131/16035,tid:11303402] LOG:  process 18987 still waiting for ShareLock on transaction 11303387 after 1000.085 ms
2022-10-06 23:40:32.840 UTC [db:pe-puppetdb,sess:633f59a0.4a2b,pid:18987,vtid:131/16035,tid:11303402] LOG:  process 18987 acquired ShareLock on transaction 11303387 after 1045.411 ms
2022-10-12 01:02:49.273 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11320,tid:0] LOG:  process 18987 still waiting for ShareLock on transaction 17880045 after 1000.109 ms
2022-10-12 01:02:53.733 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11320,tid:0] LOG:  process 18987 acquired ShareLock on transaction 17880045 after 5459.988 ms
2022-10-12 01:04:55.270 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11383,tid:0] LOG:  process 18987 still waiting for ShareLock on transaction 17881345 after 1000.071 ms
2022-10-12 01:04:58.734 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11383,tid:0] LOG:  process 18987 acquired ShareLock on transaction 17881345 after 4464.075 ms
2022-10-12 01:06:40.901 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11442,tid:0] LOG:  process 18987 still waiting for ShareLock on transaction 17882875 after 1000.073 ms
2022-10-12 01:07:22.328 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11442,tid:0] LOG:  process 18987 acquired ShareLock on transaction 17882875 after 42427.311 ms
2022-10-12 01:08:33.497 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11553,tid:0] LOG:  process 18987 still waiting for ShareLock on transaction 17884491 after 1000.185 ms
2022-10-12 01:08:36.558 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11553,tid:0] LOG:  process 18987 acquired ShareLock on transaction 17884491 after 4061.484 ms
2022-10-12 01:10:34.212 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11612,tid:0] LOG:  process 18987 still waiting for RowExclusiveLock on relation 17473 of database 16398 after 1000.052 ms at character 13
2022-10-12 01:10:39.878 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11612,tid:0] LOG:  process 18987 acquired RowExclusiveLock on relation 17473 of database 16398 after 6665.157 ms at character 13
2022-10-12 01:20:29.989 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11950,tid:0] LOG:  process 18987 still waiting for ShareLock on transaction 17898305 after 1000.116 ms
2022-10-12 01:20:41.309 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11950,tid:0] LOG:  process 18987 acquired ShareLock on transaction 17898305 after 12320.454 ms
  
~ {code}
 

On Pg_locks table:

 

 
{code:java}
locktype    | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction |  pid  |           mode           | granted | fastpath ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+--------------------------+---------+----------
relation      |    16398 |    17471 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17720 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17659 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17482 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17480 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17473 |      |       |            |               |         |       |          | 245/12073          | 18987 | AccessShareLock          | t       | t
 relation      |    16398 |    17473 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 virtualxid    |          |          |      |       | 245/12073  |               |         |       |          | 245/12073          | 18987 | ExclusiveLock            | t       | t
 transactionid |          |          |      |       |            |      17902765 |         |       |          | 245/12073          | 18987 | ExclusiveLock            | t       | f

  {code}
 *   ~ Please see Zendesk Support tab for further comments and attachments.~

Xiuqing Jiang (Jira)

unread,
Oct 12, 2022, 4:16:01 AM10/12/22
to puppe...@googlegroups.com
Xiuqing Jiang updated an issue
Customer Splunk reported that there were a lot of multi-day queries stuck in Postgres which cause Postgreql gone into maintenance mode.

Like for pid 18987:
{ {}}
{ code:java}
datid | datname | pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | query_start | state_change | wait_event_type | wait_event | state | backend_xid | backend_xmin |
16398 | pe-puppetdb | 18987 | 16387 | pe-puppetdb | PostgreSQL JDBC Driver | 10.0.168.34 | | 58688 | 2022-10-12 01:01:40.424688+00 | 2022-10-12 01:22:43.228219+00 | 2022-10-12 01:22:43.228888+00 | 2022-10-12 01:22:43.228952+00 | Client | ClientRead | idle in transaction | 17902765 | 17896313 | insert into certnames (certname) values ($1) on conflict (certname) do update set deactivated=null, expired=null where (certnames.deactivated < $2 or certnames.expired < $3)
{code}
 
 

 
 {code:java}
2022-10-06 23:40:32.795 UTC [db:pe-puppetdb,sess:633f59a0.4a2b,pid:18987,vtid:131/16035,tid:11303402] LOG: process 18987 still waiting for ShareLock on transaction 11303387 after 1000.085 ms
2022-10-06 23:40:32.840 UTC [db:pe-puppetdb,sess:633f59a0.4a2b,pid:18987,vtid:131/16035,tid:11303402] LOG: process 18987 acquired ShareLock on transaction 11303387 after 1045.411 ms
2022-10-12 01:02:49.273 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11320,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17880045 after 1000.109 ms
2022-10-12 01:02:53.733 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11320,tid:0] LOG: process 18987 acquired ShareLock on transaction 17880045 after 5459.988 ms
2022-10-12 01:04:55.270 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11383,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17881345 after 1000.071 ms
2022-10-12 01:04:58.734 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11383,tid:0] LOG: process 18987 acquired ShareLock on transaction 17881345 after 4464.075 ms
2022-10-12 01:06:40.901 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11442,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17882875 after 1000.073 ms
2022-10-12 01:07:22.328 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11442,tid:0] LOG: process 18987 acquired ShareLock on transaction 17882875 after 42427.311 ms
2022-10-12 01:08:33.497 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11553,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17884491 after 1000.185 ms
2022-10-12 01:08:36.558 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11553,tid:0] LOG: process 18987 acquired ShareLock on transaction 17884491 after 4061.484 ms
2022-10-12 01:10:34.212 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11612,tid:0] LOG: process 18987 still waiting for RowExclusiveLock on relation 17473 of database 16398 after 1000.052 ms at character 13
2022-10-12 01:10:39.878 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11612,tid:0] LOG: process 18987 acquired RowExclusiveLock on relation 17473 of database 16398 after 6665.157 ms at character 13
2022-10-12 01:20:29.989 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11950,tid:0] LOG: process 18987 still waiting for ShareLock on transaction 17898305 after 1000.116 ms
2022-10-12 01:20:41.309 UTC [db:pe-puppetdb,sess:634611f4.4a2b,pid:18987,vtid:245/11950,tid:0] LOG: process 18987 acquired ShareLock on transaction 17898305 after 12320.454 ms
 
{code}
 

On Pg_locks table:

 

 
 {code:java}
locktype    | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction |  pid  |           mode           | granted | fastpath ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+--------------------------+---------+----------
relation      |    16398 |    17471 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17720 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17659 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17482 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17480 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 relation      |    16398 |    17473 |      |       |            |               |         |       |          | 245/12073          | 18987 | AccessShareLock          | t       | t
 relation      |    16398 |    17473 |      |       |            |               |         |       |          | 245/12073          | 18987 | RowExclusiveLock         | t       | t
 virtualxid    |          |          |      |       | 245/12073  |               |         |       |          | 245/12073          | 18987 | ExclusiveLock            | t       | t
 transactionid |          |          |      |       |            |      17902765 |         |       |          | 245/12073          | 18987 | ExclusiveLock            | t       | f

  {code}
*  ~Please see Zendesk Support tab for further comments and attachments.~

Alvin Rodis (Jira)

unread,
Oct 12, 2022, 4:19:02 AM10/12/22
to puppe...@googlegroups.com
Alvin Rodis updated an issue
Change By: Alvin Rodis
Zendesk Ticket Count: 1
Zendesk Ticket IDs: 49787
Labels: jira_escalated
Reply all
Reply to author
Forward
0 new messages