View Issue Details

IDProjectCategoryView StatusLast Update
0000379Pgpool-IIBugpublic2018-04-06 10:52
ReporteryacqAssigned Tot-ishii 
PrioritynormalSeveritymajorReproducibilityalways
Status closedResolutionopen 
Platformamd64OSLinuxOS Version4.9.0-4-amd64
Product Version3.7.1 
Target VersionFixed in Version 
Summary0000379: Many connections go into state 'idle in transaction'
DescriptionSystem description:

4 node PostgreSQL 10.1 cluster
PostgreSQL running in master slave mode in sync replication. Pgpool is configured on all of them.
Application server farm (WildFly 11 with JDBC 42.2.1 driver) uses the database cluster. All of them use one database and one database user.
After some time (~20h), depend on the load, Wildfly database connection pool ends and applications server stop working.

Thank you for your help!
Additional InformationThis is a ps aux outpu after six hours of system operation:

postgres 2000 0.0 0.0 272324 110132 ? S 11:14 0:03 pgpool: db_user db 1.2.3.203(38828) idle in transaction
postgres 5967 0.0 0.0 199272 51180 ? S 09:44 0:05 pgpool: db_user db 1.2.3.205(46682) idle in transaction
postgres 8644 0.3 0.0 266836 98180 ? S 11:59 0:07 pgpool: db_user db 1.2.3.205(49540) idle in transaction
postgres 10507 0.0 0.0 242736 94360 ? S 06:13 0:08 pgpool: db_user db 1.2.3.202(50924) idle in transaction
postgres 10819 0.0 0.0 248592 114360 ? S 06:13 0:07 pgpool: db_user db 1.2.3.204(40148) idle in transaction
postgres 11063 0.0 0.0 248496 110912 ? S 06:13 0:13 pgpool: db_user db 1.2.3.207(58892) idle in transaction
postgres 15607 0.1 0.0 442484 210720 ? S 09:14 0:14 pgpool: db_user db 1.2.3.207(38816) idle in transaction
postgres 16878 0.0 0.0 219028 69684 ? S 11:29 0:01 pgpool: db_user db 1.2.3.208(35298) idle in transaction
postgres 17850 0.0 0.0 221016 80240 ? S 09:59 0:06 pgpool: db_user db 1.2.3.209(40528) idle in transaction
postgres 17852 0.0 0.0 250768 105448 ? S 09:59 0:05 pgpool: db_user db 1.2.3.207(36776) idle in transaction
postgres 21851 0.0 0.0 229600 77324 ? S 06:43 0:05 pgpool: db_user db 1.2.3.204(35394) idle in transaction
postgres 27586 0.0 0.0 236028 111000 ? S 09:29 0:07 pgpool: db_user db 1.2.3.201(58192) idle in transaction
postgres 28186 0.0 0.0 293976 137844 ? S 07:59 0:05 pgpool: db_user db 1.2.3.202(60466) idle in transaction
postgres 29081 0.1 0.0 267492 150844 ? S 11:44 0:02 pgpool: db_user db 1.2.3.204(42190) idle in transaction
postgres 29089 0.2 0.0 269704 101772 ? S 11:44 0:05 pgpool: db_user db 1.2.3.201(32908) idle in transaction
postgres 30199 0.0 0.0 354544 147744 ? S 10:44 0:03 pgpool: db_user db 1.2.3.204(42194) idle in transaction

corresponding select from pg_stat_activity:

 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 | query | backend_type
-------+------------+-------+----------+-----------------+------------------------+---------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+-----------------+------------+---------------------+-------------+--------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------
 18182 | db | 4652 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 21780 | 2018-02-07 07:19:13.203336+01 | 2018-02-07 07:48:47.198411+01 | 2018-02-07 07:48:47.198567+01 | 2018-02-07 07:48:47.198592+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 409 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 23856 | 2018-02-07 12:19:13.472664+01 | 2018-02-07 12:34:18.700803+01 | 2018-02-07 12:34:18.700823+01 | 2018-02-07 12:34:18.70437+01 | | | idle in transaction | | | BEGIN | client backend
 18182 | db | 389 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 23776 | 2018-02-07 12:19:13.298066+01 | 2018-02-07 12:34:18.447069+01 | 2018-02-07 12:34:18.447088+01 | 2018-02-07 12:34:18.447106+01 | Client | ClientRead | idle in transaction | | | BEGIN | client backend
 18182 | db | 21442 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 15284 | 2018-02-07 11:34:13.487402+01 | 2018-02-07 12:34:18.1637+01 | 2018-02-07 12:34:18.403103+01 | 2018-02-07 12:34:18.689478+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 21441 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 15276 | 2018-02-07 11:34:13.476092+01 | 2018-02-07 12:34:18.34388+01 | 2018-02-07 12:34:18.6972+01 | 2018-02-07 12:34:18.697317+01 | Client | ClientRead | idle in transaction | | | SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.relname = 'tag' AND c.relnamespace = n.oid AND n.nspname ~ '^pg_temp_' | client backend
 18182 | db | 20213 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 53370 | 2018-02-07 10:34:13.412162+01 | 2018-02-07 11:10:42.886563+01 | 2018-02-07 11:10:42.886675+01 | 2018-02-07 11:10:42.886756+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 31710 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 43414 | 2018-02-07 09:34:13.235729+01 | 2018-02-07 10:29:59.998702+01 | 2018-02-07 10:29:59.998908+01 | 2018-02-07 10:29:59.998927+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 5638 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 50760 | 2018-02-07 10:19:13.225039+01 | 2018-02-07 10:33:26.24564+01 | 2018-02-07 10:33:26.245775+01 | 2018-02-07 10:33:26.245792+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 16067 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 15034 | 2018-02-07 06:34:16.477763+01 | 2018-02-07 07:04:50.111409+01 | 2018-02-07 07:04:50.112643+01 | 2018-02-07 07:04:50.112761+01 | Client | ClientRead | idle in transaction | | 285041543 | select distinct document0_.id as id1_24_, document0_.alias as alias2_24_, document0_.content as content3_24_, document0_.created_at as created_4_24_, document0_.mime_type as mime_typ5_24_, document0_.modified_at as modified6_24_, document0_.title as title7_24_, document0_.type as type8_24_ from public.document document0_ left outer join public.document_to_platform platforms1_ on document0_.id=platforms1_.document_id left outer join public.platform platform2_ on platforms1_.platform_id=platform2_.id where document0_.alias=$1 and platform2_.name=$2 | client backend
 18182 | db | 5628 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 50704 | 2018-02-07 10:19:13.131979+01 | 2018-02-07 10:45:45.828937+01 | 2018-02-07 10:45:45.829558+01 | 2018-02-07 10:45:45.8296+01 | Client | ClientRead | idle in transaction | | 285268991 | select category0_.id as id1_12_, category0_.active as active2_12_, category0_.external_id as external3_12_, category0_.label as label4_12_, category0_.label_plus as label_pl5_12_, category0_.name as name6_12_, category0_.nc_plus as nc_plus7_12_, category0_.promoted as promoted8_12_, category0_.rank as rank9_12_, category0_.slug as slug10_12_, category0_.type as type11_12_ from public.category category0_ where category0_.slug=$1 | client backend
 18182 | db | 19321 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 40754 | 2018-02-07 09:19:13.055201+01 | 2018-02-07 11:09:46.785898+01 | 2018-02-07 11:09:46.785982+01 | 2018-02-07 11:09:46.78604+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 16002 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 14514 | 2018-02-07 06:34:15.993213+01 | 2018-02-07 06:56:28.203083+01 | 2018-02-07 06:56:28.203263+01 | 2018-02-07 06:56:28.203277+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 31818 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 28692 | 2018-02-07 08:04:13.111747+01 | 2018-02-07 08:29:34.028747+01 | 2018-02-07 08:29:34.028961+01 | 2018-02-07 08:29:34.029057+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 7237 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 12034 | 2018-02-07 11:19:13.412844+01 | 2018-02-07 11:31:53.635738+01 | 2018-02-07 11:31:53.635898+01 | 2018-02-07 11:31:53.636008+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 19319 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 40738 | 2018-02-07 09:19:13.049489+01 | 2018-02-07 11:29:20.994176+01 | 2018-02-07 11:29:20.994356+01 | 2018-02-07 11:29:20.994375+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26809 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26740 | 2018-02-07 12:34:13.263828+01 | 2018-02-07 12:34:18.635677+01 | 2018-02-07 12:34:18.671066+01 | 2018-02-07 12:34:18.700493+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 15974 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 14290 | 2018-02-07 06:34:15.90102+01 | 2018-02-07 07:14:42.453686+01 | 2018-02-07 07:14:42.453889+01 | 2018-02-07 07:14:42.453916+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 8449 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 38484 | 2018-02-07 09:04:13.183743+01 | 2018-02-07 09:24:41.249468+01 | 2018-02-07 09:24:41.249559+01 | 2018-02-07 09:24:41.249638+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 3382 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 56382 | 2018-02-07 10:49:13.202405+01 | 2018-02-07 10:55:37.933918+01 | 2018-02-07 10:55:37.934091+01 | 2018-02-07 10:55:37.934111+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 3380 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 56366 | 2018-02-07 10:49:13.199299+01 | 2018-02-07 11:07:01.733706+01 | 2018-02-07 11:07:01.733852+01 | 2018-02-07 11:07:01.733872+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26813 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26772 | 2018-02-07 12:34:13.288343+01 | 2018-02-07 12:34:18.698497+01 | 2018-02-07 12:34:18.698762+01 | 2018-02-07 12:34:18.698842+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26794 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26684 | 2018-02-07 12:34:13.115732+01 | 2018-02-07 12:34:18.542806+01 | 2018-02-07 12:34:18.543069+01 | 2018-02-07 12:34:18.556519+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 15945 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 14058 | 2018-02-07 06:34:15.837159+01 | 2018-02-07 07:05:00.008581+01 | 2018-02-07 07:05:00.008722+01 | 2018-02-07 07:05:00.00885+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 20178 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 53122 | 2018-02-07 10:34:13.067331+01 | 2018-02-07 11:25:02.220585+01 | 2018-02-07 11:25:02.22122+01 | 2018-02-07 11:25:02.221229+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 20899 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 59512 | 2018-02-07 11:04:13.101684+01 | 2018-02-07 12:34:18.55589+01 | 2018-02-07 12:34:18.666828+01 | 2018-02-07 12:34:18.703771+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 3372 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 56302 | 2018-02-07 10:49:13.170234+01 | 2018-02-07 11:08:39.835148+01 | 2018-02-07 11:08:39.835287+01 | 2018-02-07 11:08:39.835358+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 21245 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 47998 | 2018-02-07 10:04:13.008238+01 | 2018-02-07 11:01:11.33059+01 | 2018-02-07 11:01:11.330815+01 | 2018-02-07 11:01:11.330886+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26778 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26612 | 2018-02-07 12:34:13.076964+01 | 2018-02-07 12:34:18.388038+01 | 2018-02-07 12:34:18.475766+01 | 2018-02-07 12:34:18.480373+01 | Client | ClientRead | idle in transaction | | | SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"public"."section_element"') AND c.relpersistence = 'u' | client backend
 18182 | db | 19566 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 59252 | 2018-02-07 11:03:30.70148+01 | 2018-02-07 11:37:55.097316+01 | 2018-02-07 11:37:55.097603+01 | 2018-02-07 11:37:55.097639+01 | Client | ClientRead | idle in transaction | | 285361462 | select count(logo0_.id) as col_0_0_ from public.logo logo0_ | client backend
 18182 | db | 26774 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26604 | 2018-02-07 12:34:13.067208+01 | 2018-02-07 12:34:18.536351+01 | 2018-02-07 12:34:18.552834+01 | 2018-02-07 12:34:18.553022+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26772 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26588 | 2018-02-07 12:34:13.063576+01 | 2018-02-07 12:34:18.671137+01 | 2018-02-07 12:34:18.671607+01 | 2018-02-07 12:34:18.671747+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26770 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26580 | 2018-02-07 12:34:13.061555+01 | 2018-02-07 12:34:18.445423+01 | 2018-02-07 12:34:18.513103+01 | 2018-02-07 12:34:18.623709+01 | Client | ClientRead | idle in transaction | | 285467469 | select distinct section0_.item_id as id1_30_0_, algorithms1_.id as id1_66_1_, sectionalg2_.id as id1_65_2_, elements3_.id as id1_67_3_, item4_.id as id1_30_4_, section0_1_.active as active2_30_0_, section0_1_.created_at as created_3_30_0_, section0_1_.deleted_at as deleted_4_30_0_, section0_1_.description as descript5_30_0_, section0_1_.external_uid as external6_30_0_, section0_1_.hidden as hidden7_30_0_, section0_1_.lead as lead8_30_0_, section0_1_.logo_id as logo_id15_30_0_, section0_1_.main_category_id as main_ca16_30_0_, section0_1_.modified_at as modified9_30_0_, section0_1_.nc_plus as nc_plus10_30_0_, section0_1_.since as since11_30_0_, section0_1_.till as till12_30_0_, section0_1_.title as title13_30_0_, section0_1_.uhd as uhd14_30_0_, section0_.catalog as catalog1_64_0_, section0_.color as color2_64_0_, section0_.content_type as content_3_64_0_, section0_.external_collection_id as external4_64_0_, section0_.external_container_id as external5_64_0_, section0_.label as label6_64_0_, section0_.layout as | client backend
 18182 | db | 31664 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 43136 | 2018-02-07 09:34:13.005281+01 | 2018-02-07 11:06:23.688322+01 | 2018-02-07 11:06:23.688479+01 | 2018-02-07 11:06:23.688564+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 20158 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 52970 | 2018-02-07 10:34:12.982714+01 | 2018-02-07 11:06:22.638821+01 | 2018-02-07 11:06:22.639173+01 | 2018-02-07 11:06:22.639197+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 31516 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 23278 | 2018-02-07 12:18:30.708757+01 | 2018-02-07 12:34:18.262434+01 | 2018-02-07 12:34:18.262452+01 | 2018-02-07 12:34:18.273907+01 | Client | ClientRead | idle in transaction | | | BEGIN | client backend
 18182 | db | 26759 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26540 | 2018-02-07 12:34:13.035463+01 | 2018-02-07 12:34:18.683786+01 | 2018-02-07 12:34:18.699588+01 | 2018-02-07 12:34:18.701313+01 | Client | ClientRead | idle in transaction | | | SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"public"."payment"') AND c.relpersistence = 'u' | client backend
 18182 | db | 31515 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 23270 | 2018-02-07 12:18:30.684398+01 | 2018-02-07 12:34:18.516229+01 | 2018-02-07 12:34:18.516246+01 | 2018-02-07 12:34:18.516277+01 | Client | ClientRead | idle in transaction | | | BEGIN | client backend
 18182 | db | 31514 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 23262 | 2018-02-07 12:18:30.668595+01 | 2018-02-07 12:34:18.639954+01 | 2018-02-07 12:34:18.671157+01 | 2018-02-07 12:34:18.698881+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26751 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26508 | 2018-02-07 12:34:13.019046+01 | 2018-02-07 12:34:18.687763+01 | 2018-02-07 12:34:18.689346+01 | 2018-02-07 12:34:18.700729+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 26750 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26500 | 2018-02-07 12:34:13.016965+01 | 2018-02-07 12:34:18.681405+01 | 2018-02-07 12:34:18.68169+01 | 2018-02-07 12:34:18.681786+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 31122 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 28092 | 2018-02-07 08:03:30.540892+01 | 2018-02-07 08:26:03.96578+01 | 2018-02-07 08:26:03.982088+01 | 2018-02-07 08:26:03.982648+01 | Client | ClientRead | idle in transaction | | 285089664 | select count(vod0_.product_id) as col_0_0_ from public.vod vod0_ inner join public.product vod0_1_ on vod0_.product_id=vod0_1_.item_id inner join public.item vod0_2_ on vod0_.product_id=vod0_2_.id left outer join public.display_schedule displaysch1_ on vod0_.product_id=displaysch1_.item_id left outer join public.platform platform2_ on displaysch1_.platform_id=platform2_.id left outer join public.item_to_platform platforms3_ on vod0_.product_id=platforms3_.item_id left outer join public.platform platform4_ on platforms3_.platform_id=platform4_.id where vod0_2_.active=true and (vod0_2_.deleted_at is null) and vod0_2_.since<=$1 and (vod0_2_.till is null or vod0_2_.till>=$2) and vod0_2_.hidden=false and platform2_.name=$3 and (vod0_.type in ($4 , $5)) and displaysch1_.since<=$6 and (displaysch1_.till is null or displaysch1_.till>=$7) and (vod0_.external_program_id in (144 , 5008 , 4997 , 4998 , 9017 , 5001 , 5002 , 5005 , 4286 , 8271)) and (vod0_.product_id not in (1628)) and platform4_.name=$8 | client backend
 18182 | db | 7461 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 31034 | 2018-02-07 08:19:13.003497+01 | 2018-02-07 08:58:44.946061+01 | 2018-02-07 08:58:44.946256+01 | 2018-02-07 08:58:44.946275+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 29080 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 35564 | 2018-02-07 08:48:30.598965+01 | 2018-02-07 09:08:02.727991+01 | 2018-02-07 09:08:02.728146+01 | 2018-02-07 09:08:02.728167+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 3345 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 56102 | 2018-02-07 10:49:13.06065+01 | 2018-02-07 11:17:15.121541+01 | 2018-02-07 11:17:15.121756+01 | 2018-02-07 11:17:15.121781+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 15608 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 12692 | 2018-02-07 06:33:33.408018+01 | 2018-02-07 07:10:06.185368+01 | 2018-02-07 07:10:06.185975+01 | 2018-02-07 07:10:06.185996+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 31038 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 42908 | 2018-02-07 09:33:30.540991+01 | 2018-02-07 09:56:52.377297+01 | 2018-02-07 09:56:52.377699+01 | 2018-02-07 09:56:52.377719+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 6830 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 11670 | 2018-02-07 11:18:30.567456+01 | 2018-02-07 11:24:40.562212+01 | 2018-02-07 11:24:40.562362+01 | 2018-02-07 11:24:40.562465+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
 18182 | db | 25399 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 26326 | 2018-02-07 12:33:30.540779+01 | 2018-02-07 12:34:18.67064+01 | 2018-02-07 12:34:18.67066+01 | 2018-02-07 12:34:18.670665+01 | Client | ClientRead | idle in transaction | | | BEGIN | client backend
 18182 | db | 6828 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 11654 | 2018-02-07 11:18:30.529987+01 | 2018-02-07 12:34:18.53449+01 | 2018-02-07 12:34:18.534509+01 | 2018-02-07 12:34:18.534518+01 | Client | ClientRead | idle in transaction | | | BEGIN | client backend
 18182 | db | 20817 | 16462 | db_user | PostgreSQL JDBC Driver | 1.2.3.51 | | 47770 | 2018-02-07 10:03:30.536564+01 | 2018-02-07 10:56:23.49818+01 | 2018-02-07 10:56:23.498344+01 | 2018-02-07 10:56:23.498366+01 | Client | ClientRead | idle in transaction | | | SELECT current_setting('transaction_isolation') | client backend
(50 rows)

I also attach output from select * from pg_locks, maybe it will be useful.

  locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | fastpath
------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+-----------------+---------+----------
 relation | 18182 | 19257 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 19225 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 19415 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 19241 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 19259 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 19407 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 19219 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 47557 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18387 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18471 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18334 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18365 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18418 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18373 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18476 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 relation | 18182 | 18620 | | | | | | | | 439/18834 | 386 | AccessShareLock | t | t
 virtualxid | | | | | 439/18834 | | | | | 439/18834 | 386 | ExclusiveLock | t | t
 virtualxid | | | | | 301/11181 | | | | | 301/11181 | 13298 | ExclusiveLock | t | t
 virtualxid | | | | | 319/10876 | | | | | 319/10876 | 8566 | ExclusiveLock | t | t
 virtualxid | | | | | 246/5252 | | | | | 246/5252 | 8449 | ExclusiveLock | t | t
 virtualxid | | | | | 496/2952 | | | | | 496/2952 | 4652 | ExclusiveLock | t | t
 virtualxid | | | | | 326/5003 | | | | | 326/5003 | 20923 | ExclusiveLock | t | t
 virtualxid | | | | | 69/2471 | | | | | 69/2471 | 1682 | ExclusiveLock | t | t
 virtualxid | | | | | 159/14385 | | | | | 159/14385 | 5589 | ExclusiveLock | t | t
 virtualxid | | | | | 12/15001 | | | | | 12/15001 | 20817 | ExclusiveLock | t | t
 virtualxid | | | | | 113/5791 | | | | | 113/5791 | 20158 | ExclusiveLock | t | t
 virtualxid | | | | | 130/4836 | | | | | 130/4836 | 26765 | ExclusiveLock | t | t
 virtualxid | | | | | 31/17096 | | | | | 31/17096 | 13249 | ExclusiveLock | t | t
 virtualxid | | | | | 266/8122 | | | | | 266/8122 | 7237 | ExclusiveLock | t | t
 virtualxid | | | | | 30/5008 | | | | | 30/5008 | 31038 | ExclusiveLock | t | t
 virtualxid | | | | | 385/11874 | | | | | 385/11874 | 21437 | ExclusiveLock | t | t
 virtualxid | | | | | 390/9401 | | | | | 390/9401 | 31710 | ExclusiveLock | t | t
 virtualxid | | | | | 54/4220 | | | | | 54/4220 | 7461 | ExclusiveLock | t | t
 virtualxid | | | | | 224/2406 | | | | | 224/2406 | 15945 | ExclusiveLock | t | t
 virtualxid | | | | | 396/7937 | | | | | 396/7937 | 20213 | ExclusiveLock | t | t
 virtualxid | | | | | 335/9693 | | | | | 335/9693 | 346 | ExclusiveLock | t | t
 virtualxid | | | | | 211/7857 | | | | | 211/7857 | 20178 | ExclusiveLock | t | t
 relation | 18182 | 19335 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 19257 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 114307 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 114306 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 114304 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 19209 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 18471 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 114301 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 relation | 18182 | 18339 | | | | | | | | 346/5471 | 16067 | AccessShareLock | t | t
 virtualxid | | | | | 346/5471 | | | | | 346/5471 | 16067 | ExclusiveLock | t | t
 virtualxid | | | | | 245/19881 | | | | | 245/19881 | 26805 | ExclusiveLock | t | t
 virtualxid | | | | | 42/7537 | | | | | 42/7537 | 3345 | ExclusiveLock | t | t
 virtualxid | | | | | 281/2132 | | | | | 281/2132 | 16002 | ExclusiveLock | t | t
 virtualxid | | | | | 180/7656 | | | | | 180/7656 | 26780 | ExclusiveLock | t | t
 virtualxid | | | | | 239/5018 | | | | | 239/5018 | 3380 | ExclusiveLock | t | t
 virtualxid | | | | | 196/3947 | | | | | 196/3947 | 3372 | ExclusiveLock | t | t
 virtualxid | | | | | 273/2403 | | | | | 273/2403 | 31818 | ExclusiveLock | t | t
 relation | 18182 | 19429 | | | | | | | | 22/15978 | 7207 | AccessShareLock | t | t
 relation | 18182 | 19349 | | | | | | | | 22/15978 | 7207 | AccessShareLock | t | t
 relation | 18182 | 19315 | | | | | | | | 22/15978 | 7207 | AccessShareLock | t | t
 relation | 18182 | 19299 | | | | | | | | 22/15978 | 7207 | AccessShareLock | t | t
 relation | 18182 | 18583 | | | | | | | | 22/15978 | 7207 | AccessShareLock | t | t
 virtualxid | | | | | 22/15978 | | | | | 22/15978 | 7207 | ExclusiveLock | t | t
 relation | 18182 | 19416 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19412 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19391 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19384 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19219 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19259 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 47557 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19406 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19394 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 19375 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 18387 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 18471 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 18334 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 18373 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 18476 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 relation | 18182 | 18620 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | t
 virtualxid | | | | | 55/8005 | | | | | 55/8005 | 31122 | ExclusiveLock | t | t
 virtualxid | | | | | 238/5165 | | | | | 238/5165 | 26814 | ExclusiveLock | t | t
 virtualxid | | | | | 253/3432 | | | | | 253/3432 | 15974 | ExclusiveLock | t | t
 virtualxid | | | | | 233/10308 | | | | | 233/10308 | 26802 | ExclusiveLock | t | t
 virtualxid | | | | | 458/9082 | | | | | 458/9082 | 409 | ExclusiveLock | t | t
 virtualxid | | | | | 348/4555 | | | | | 348/4555 | 5638 | ExclusiveLock | t | t
 virtualxid | | | | | 117/6063 | | | | | 117/6063 | 31664 | ExclusiveLock | t | t
 virtualxid | | | | | 244/7894 | | | | | 244/7894 | 3382 | ExclusiveLock | t | t
 virtualxid | | | | | 34/3095 | | | | | 34/3095 | 15608 | ExclusiveLock | t | t
 virtualxid | | | | | 47/3961 | | | | | 47/3961 | 29080 | ExclusiveLock | t | t
 virtualxid | | | | | 283/7722 | | | | | 283/7722 | 19321 | ExclusiveLock | t | t
 virtualxid | | | | | 290/14802 | | | | | 290/14802 | 1720 | ExclusiveLock | t | t
 virtualxid | | | | | 342/15960 | | | | | 342/15960 | 21432 | ExclusiveLock | t | t
 virtualxid | | | | | 169/4655 | | | | | 169/4655 | 21245 | ExclusiveLock | t | t
 virtualxid | | | | | 19/10282 | | | | | 19/10282 | 6830 | ExclusiveLock | t | t
 relation | 18182 | 19361 | | | | | | | | 322/7625 | 5628 | AccessShareLock | t | t
 relation | 18182 | 19357 | | | | | | | | 322/7625 | 5628 | AccessShareLock | t | t
 relation | 18182 | 19189 | | | | | | | | 322/7625 | 5628 | AccessShareLock | t | t
 relation | 18182 | 18275 | | | | | | | | 322/7625 | 5628 | AccessShareLock | t | t
 virtualxid | | | | | 322/7625 | | | | | 322/7625 | 5628 | ExclusiveLock | t | t
 relation | 12995 | 11577 | | | | | | | | 356/8783 | 6526 | AccessShareLock | t | t
 virtualxid | | | | | 356/8783 | | | | | 356/8783 | 6526 | ExclusiveLock | t | t
 virtualxid | | | | | 80/12162 | | | | | 80/12162 | 26755 | ExclusiveLock | t | t
 relation | 18182 | 19241 | | | | | | | | 153/11183 | 19566 | AccessShareLock | t | t
 relation | 18182 | 18418 | | | | | | | | 153/11183 | 19566 | AccessShareLock | t | t
 virtualxid | | | | | 153/11183 | | | | | 153/11183 | 19566 | ExclusiveLock | t | t
 virtualxid | | | | | 185/6092 | | | | | 185/6092 | 330 | ExclusiveLock | t | t
 virtualxid | | | | | 43/13169 | | | | | 43/13169 | 26747 | ExclusiveLock | t | t
 virtualxid | | | | | 132/7884 | | | | | 132/7884 | 26766 | ExclusiveLock | t | t
 virtualxid | | | | | 249/6387 | | | | | 249/6387 | 26807 | ExclusiveLock | t | t
 virtualxid | | | | | 263/23344 | | | | | 263/23344 | 19319 | ExclusiveLock | t | t
 virtualxid | | | | | 270/9359 | | | | | 270/9359 | 26812 | ExclusiveLock | t | t
 virtualxid | | | | | 52/11751 | | | | | 52/11751 | 19545 | ExclusiveLock | t | t
 virtualxid | | | | | 107/6206 | | | | | 107/6206 | 1688 | ExclusiveLock | t | t
 relation | 18182 | 19420 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19390 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19428 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19399 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19422 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 329235 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19407 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19257 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19225 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19207 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19335 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
 relation | 18182 | 19408 | | | | | | | | 55/8005 | 31122 | AccessShareLock | t | f
(122 rows)
TagsNo tags attached.

Activities

t-ishii

2018-02-07 22:33

developer   ~0001918

Is it possible to provide Pgpool-II debug logs?

yacq

2018-02-07 23:13

reporter   ~0001919

which debug variables should I turn on/change?

yacq

2018-02-07 23:33

reporter   ~0001920

current logging settings:

log_destination = 'syslog'
log_line_prefix = '%t: pid %p: '
log_connections = off
log_hostname = off
log_statement = off
log_per_node_statement = off
log_standby_delay = 'none'
#log_error_verbosity = default
#client_min_messages = notice
#log_min_messages = warning

yacq

2018-02-13 02:57

reporter  

pgpool2.log.gz (602,903 bytes)

yacq

2018-02-13 02:57

reporter   ~0001922

Hello,

I've attached the file with a few minutes of server work. I hope it will be useful.

t-ishii

2018-02-13 08:35

developer   ~0001923

Thank you for the log. However I don't see any problem in the log. Those sessions in the log ended normally (transaction state is "I" (idle), not "T" (idle in a transaction)". Do you actually see the related PostgreSQL backend go in to "idle in a transaction state"?

yacq

2018-02-13 20:23

reporter   ~0001924

Hi,

I have a new log from the period when the problem occurred.
I'm attaching the output from pg_locks and pg_stat_activity.

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 | query | backend_type
-------+----------------+------+----------+---------------------+------------------------+----------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+-----------------+------------+---------------------+-------------+--------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------
 16453 | tvn-player-uat | 9584 | 16421 | tvn-player-uat_user | PostgreSQL JDBC Driver | 10.140.148.133 | | 59192 | 2018-02-13 10:00:00.004064+01 | 2018-02-13 11:45:01.832309+01 | 2018-02-13 11:46:47.800418+01 | 2018-02-13 11:46:59.523179+01 | Client | ClientRead | idle in transaction | 3505817 | | delete from public.program_recording where epg_id in ($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 , $28 , $29 , $30 , $31 , $32 , $33 , $34 , $35 , $36 , $37 , $38 , $39 , $40 , $41 , $42 , $43 , $44 , $45 , $46 , $47 , $48 , $49 , $50 , $51 , $52 , $53 , $54 , $55 , $56 , $57 , $58 , $59 , $60 , $61 , $62 , $63 , $64 , $65 , $66 , $67 , $68 , $69 , $70 , $71 , $72 , $73 , $74 , $75 , $76 , $77 , $78 , $79 , $80 , $81 , $82 , $83 , $84 , $85 , $86 , $87 , $88 , $89 , $90 , $91 , $92 , $93 , $94 , $95 , $96 , $97 , $98 , $99 , $100) | client backend
(1 row)


   locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | fastpath
---------------+----------+----------+------+-------+------------+---------------+---------+--------+----------+--------------------+-------+---------------------+---------+----------
 virtualxid | | | | | 8/316852 | | | | | 8/316852 | 12389 | ExclusiveLock | t | t
 relation | 16453 | 16527 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 18204 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 18181 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 18163 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 18160 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 18038 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 16820 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | t
 relation | 16453 | 2685 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 2684 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 3455 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 2663 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 2662 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 2615 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 1259 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 18042 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 relation | 16453 | 16479 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | t
 virtualxid | | | | | 5/367192 | | | | | 5/367192 | 9584 | ExclusiveLock | t | t
 relation | 12981 | 11577 | | | | | | | | 21/231192 | 18351 | AccessShareLock | t | t
 virtualxid | | | | | 21/231192 | | | | | 21/231192 | 18351 | ExclusiveLock | t | t
 relation | 16453 | 18198 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18198 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18015 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18015 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18181 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18175 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18175 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17959 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17959 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16645 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16645 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 0 | | | | | | 1260 | 16421 | 0 | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 16758 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16758 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16620 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16620 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16750 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16750 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122120 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18151 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18151 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122125 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18005 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18179 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18179 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122123 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18201 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18201 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16660 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16660 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16605 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16605 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16589 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16589 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18158 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18158 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18199 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18199 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18206 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18206 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18026 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18026 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18094 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18094 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16505 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16864 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16801 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 18017 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18017 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18040 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17977 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17977 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17938 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17938 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18193 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18193 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16527 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 18191 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18191 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18196 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18196 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122121 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 122121 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122121 | | | | | | | | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18123 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18123 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17967 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17967 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17910 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18168 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18168 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122119 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18134 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 object | 16453 | | | | | | 2615 | 35514 | 0 | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18178 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18178 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18204 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18172 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18172 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16642 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16642 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122135 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 17961 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17961 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18186 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18186 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17951 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17951 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18163 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
relation | 16453 | 16636 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16636 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18137 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18137 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18197 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18197 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17953 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17953 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18174 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18174 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18187 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18187 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18160 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 122118 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 122118 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122118 | | | | | | | | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18013 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18013 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18177 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18177 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122124 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 122124 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122124 | | | | | | | | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 16771 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16771 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16666 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16666 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18164 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18164 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18202 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18202 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 16745 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 16745 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16745 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122126 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 16731 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 18169 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 16628 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 16628 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16628 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17963 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17963 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 113930 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 113930 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18162 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18162 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17945 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17945 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17957 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17957 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122134 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 16648 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16648 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 object | 16453 | | | | | | 1247 | 122122 | 0 | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 16639 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16639 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18166 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18166 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18195 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18195 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122133 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 122133 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 122133 | | | | | | | | 5/367192 | 9584 | AccessExclusiveLock | t | f
 relation | 16453 | 18038 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 16657 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 16657 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16657 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 18194 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 18194 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17955 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17955 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17973 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17973 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 relation | 16453 | 17914 | | | | | | | | 5/367192 | 9584 | AccessShareLock | t | f
 relation | 16453 | 17914 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f
 transactionid | | | | | | 3505817 | | | | 5/367192 | 9584 | ExclusiveLock | t | f
 relation | 16453 | 16820 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16872 | | | | | | | | 5/367192 | 9584 | RowShareLock | t | f
 relation | 16453 | 16872 | | | | | | | | 5/367192 | 9584 | RowExclusiveLock | t | f

pgpool2_iit.log.bz2 (4,790,313 bytes)

t-ishii

2018-02-14 08:13

developer   ~0001925

It seems Pgpool child pid 21310 got stuck while waiting for message from backend 0:
Feb 13 11:46:59 bo3-uat pgpool[21310]: [119888-1] 2018-02-13 11:46:59: pid 21310: DEBUG: reading backend data packet kind
Feb 13 11:46:59 bo3-uat pgpool[21310]: [119888-2] 2018-02-13 11:46:59: pid 21310: DETAIL: master node id: 0

The reason why pgpool wanted to get new message from backend 0 is, backend 1 has some pending message, that makes pgpool thinks backend 0 may have new message as well.

Feb 13 11:46:59 bo3-uat pgpool[21310]: [119773-1] 2018-02-13 11:46:59: pid 21310: DEBUG: pool_read: read 260 bytes from backend 1

It is interesting that backend 1 sends as long as 260 bytes message because pgpool did not send to backend 1 anything other than "Sync" message, which should return only 6 ytes.

Can you share backend 1 log so that I could what was going on when backend 1 produced 260 bytes of message?

yacq

2018-02-14 19:22

reporter   ~0001926

on backend 1 I see only such entries in the logs:

2018-02-13 11:46:48.533 CET [21917] db_user@db FATAL: terminating connection due to conflict with recovery
2018-02-13 11:46:48.533 CET [21917] db_user@db DETAIL: User was holding shared buffer pin for too long.
2018-02-13 11:46:48.533 CET [21917] db_user@db HINT: In a moment you should be able to reconnect to the database and repeat your command.

t-ishii

2018-02-14 21:24

developer   ~0001927

That message on node 1 must be the cause of Pgpool-II getting stuck. Let me think how Pgpool-II can deal with it.

By the way, "User was holding shared buffer pin for too long" sounds pretty unusual to me and smells like a PostgreSQL bug...

t-ishii

2018-02-15 07:24

developer   ~0001928

I polled the PostgreSQL mailing list and knew that "User was holding shared buffer pin for too long" is normal. Sorry for noise.

t-ishii

2018-02-16 10:54

developer   ~0001931

Ok, here is a patch trying to solve the problem. If something unusual happens while trying to read message from master backend, abort the session. Aborting session sounds awful, but PostgreSQL terminates the session if recovery conflict happens anyway.

t-ishii

2018-02-16 10:56

developer  

pgpool_hung.diff (1,422 bytes)
diff --git a/src/protocol/pool_process_query.c b/src/protocol/pool_process_query.c
index 31c773f..8277ece 100644
--- a/src/protocol/pool_process_query.c
+++ b/src/protocol/pool_process_query.c
@@ -3168,10 +3168,30 @@ void read_kind_from_backend(POOL_CONNECTION *frontend, POOL_CONNECTION_POOL *bac
 			 */
 			if (previous_message == NULL)
 			{
-				/* no previous message. let's unset query in progress flag. */
+				/*
+				 * No pending message nor previous message. This means that
+				 * there's no frontend message to be processed. Check master
+				 * node if there's a pending data remains. If no pending
+				 * message remains in the master node, we need to abort this
+				 * session since we don't know how to do it. Possible scenario
+				 * is, something like recovery conflict raises in standby.
+				 */
+				pool_unset_query_in_progress();
+
+				pool_set_timeout(1);	/* set arbitrary time out 1 second for pool_check_fd() */
+
+				if (!pool_ssl_pending(MASTER(backend)) &&
+					pool_read_buffer_is_empty(MASTER(backend)) &&
+					pool_check_fd(MASTER(backend)) != 0)
+				{
+					pool_set_timeout(-1);
+					ereport(ERROR,
+							(errmsg("read_kind_from_backend: no previous message and no data in the master node")));
+				}
+				pool_set_timeout(-1);
+
 				ereport(DEBUG1,
 						(errmsg("read_kind_from_backend: no previous message")));
-				pool_unset_query_in_progress();
 			}
 			else
 			{
pgpool_hung.diff (1,422 bytes)

t-ishii

2018-02-26 14:55

developer   ~0001940

Have you had a chance to test the patch?

yacq

2018-02-26 23:57

reporter   ~0001942

Yes. I applied the patch to version 3.7.1 but the problem remained.
I suspect that I have not provided you with the right logs.
I'm working on collecting them.

BTW: PostgreSQL 10.2 and PgPool 3.7.2 do not solve my problem.

yacq

2018-02-27 00:00

reporter   ~0001943

It seems to me that the problem arises in the query SELECT current_setting('transaction_isolation')

t-ishii

2018-02-27 06:09

developer   ~0001944

I need a log after applying the patch.

t-ishii

2018-03-30 07:33

developer   ~0001983

No response over 1 month. I am going to close this issue.

yacq

2018-03-30 17:53

reporter   ~0001984

Hi,

I solved the problem by switching JDBC driver option preferQueryMode from default value 'extend' to 'simple'.

Thank you for your help

t-ishii

2018-04-06 10:51

developer   ~0001987

Still question remains why extended protocol behaves like this. Anyway issue closed.

Issue History

Date Modified Username Field Change
2018-02-07 21:08 yacq New Issue
2018-02-07 22:33 t-ishii Note Added: 0001918
2018-02-07 23:13 yacq Note Added: 0001919
2018-02-07 23:33 yacq Note Added: 0001920
2018-02-13 02:57 yacq File Added: pgpool2.log.gz
2018-02-13 02:57 yacq Note Added: 0001922
2018-02-13 08:35 t-ishii Note Added: 0001923
2018-02-13 08:36 t-ishii Assigned To => t-ishii
2018-02-13 08:36 t-ishii Status new => assigned
2018-02-13 20:23 yacq File Added: pgpool2_iit.log.bz2
2018-02-13 20:23 yacq Note Added: 0001924
2018-02-14 08:13 t-ishii Note Added: 0001925
2018-02-14 08:14 t-ishii Status assigned => feedback
2018-02-14 19:22 yacq Note Added: 0001926
2018-02-14 19:22 yacq Status feedback => assigned
2018-02-14 21:24 t-ishii Note Added: 0001927
2018-02-15 07:24 t-ishii Note Added: 0001928
2018-02-16 10:54 t-ishii Note Added: 0001931
2018-02-16 10:56 t-ishii File Added: pgpool_hung.diff
2018-02-16 10:56 t-ishii Status assigned => feedback
2018-02-26 14:55 t-ishii Note Added: 0001940
2018-02-26 23:57 yacq Note Added: 0001942
2018-02-26 23:57 yacq Status feedback => assigned
2018-02-27 00:00 yacq Note Added: 0001943
2018-02-27 06:09 t-ishii Note Added: 0001944
2018-02-27 06:09 t-ishii Status assigned => feedback
2018-03-30 07:33 t-ishii Note Added: 0001983
2018-03-30 17:53 yacq Note Added: 0001984
2018-03-30 17:53 yacq Status feedback => assigned
2018-04-06 10:51 t-ishii Note Added: 0001987
2018-04-06 10:52 t-ishii Status assigned => closed