View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0000246 | Pgpool-II | Bug | public | 2016-09-16 00:00 | 2016-12-20 14:02 |
| Reporter | tschmidt82 | Assigned To | t-ishii | ||
| Priority | high | Severity | major | Reproducibility | always |
| Status | closed | Resolution | open | ||
| Platform | Dell Server | OS | CentOS Linux | OS Version | 7.2.1511 |
| Product Version | 3.5.3 | ||||
| Summary | 0000246: PGPool "idle in transaction" | ||||
| Description | System Description: we have a 3 node PostgreSQL Cluster with PostgreSQL running in master slave mode in sync replication. PGPool is configured on all of them. Both configurations are attached PGPool creates this "idle in transaction" connection and is using significant large number of sockets(2000-4000) after a while. To determine this connection, I used select * from pg_stat_activity where state = 'idle in transaction' 25925;"db_name";127001;10;"postgres";"";"88.198.110.35";"";48852;"2016-09-15 15:50:38.95095+02";"2016-09-15 15:55:17.152672+02";"2016-09-15 15:55:17.154484+02";"2016-09-15 15:55:17.154536+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1160"."retailer"') AND c.relpersistence = 'u'" 25925;"db_name";134728;10;"postgres";"";"88.198.110.35";"";59664;"2016-09-15 16:15:39.050716+02";"2016-09-15 16:20:38.846583+02";"2016-09-15 16:20:38.849911+02";"2016-09-15 16:20:38.84997+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1072"."store"') AND c.relpersistence = 'u'" 25925;"db_name";52866;10;"postgres";"";"88.198.110.35";"";55512;"2016-09-15 11:45:38.358258+02";"2016-09-15 13:35:11.503331+02";"2016-09-15 13:35:11.508761+02";"2016-09-15 13:35:11.508807+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1074"."store_opening_hours"') AND c.relpersistence = 'u'" I'm finally not sure if this two issues have a relation. Thank you very much for your help! With kind regards T.Schmidt | ||||
| Steps To Reproduce | normal DB usage through pgpool | ||||
| Tags | No tags attached. | ||||
|
|
|
|
|
Are you sure that the backend process is actually in idle in transaction state? I suspect pg_stat_activity reports false state (it's a known limitation of pg_stat_activity). You can check it by inspecting the process specified by "pid" column of pg_stat_activity using ps command. If it is, ps shows a line something like: postgres: t-ishii test [local] idle in transaction |
|
|
Hi, thank you for the quick response Sorry, for not serving the 'ps -aux' output, this time with more details. /Cheers Tobi [root@Server01 ~]# ps -aux | egrep 'idle in transaction' root 3929 0.0 0.0 99284 9404 ? S 00:34 0:06 pgpool: postgres db_name_live Server01(45766) idle in transaction root 19529 0.0 0.0 112652 980 pts/0 S+ 09:26 0:00 grep -E --color=auto idle in transaction postgres 20680 0.0 0.0 486328 28908 ? Ss 01:29 0:00 postgres: postgres db_name_live 1.1.1.35(47438) idle in transaction postgres 29836 0.0 0.0 486272 29252 ? Ss 01:59 0:00 postgres: postgres db_name_live 1.1.1.35(60228) idle in transaction root 32219 0.0 0.0 98916 8984 ? S Sep15 0:02 pgpool: postgres db_name_live Server01(41042) idle in transaction root 32226 0.0 0.0 99348 9804 ? S Sep15 0:08 pgpool: postgres db_name_live Server01(56798) idle in transaction root 32233 0.0 0.0 99104 9360 ? S Sep15 0:06 pgpool: postgres db_name_live Server01(56887) idle in transaction root 32236 0.0 0.0 99008 9204 ? S Sep15 0:04 pgpool: postgres db_name_live Server01(58543) idle in transaction root 32246 0.0 0.0 99256 9500 ? S Sep15 0:06 pgpool: postgres db_name_live Server01(45146) idle in transaction root 32253 0.0 0.0 98804 9052 ? S Sep15 0:03 pgpool: postgres db_name_live Server01(56918) idle in transaction root 32266 0.0 0.0 98960 9308 ? S Sep15 0:05 pgpool: postgres db_name_live Server01(33980) idle in transaction root 32280 0.0 0.0 99016 9356 ? S Sep15 0:04 pgpool: postgres db_name_live Server01(45142) idle in transaction root 32285 0.0 0.0 98928 9176 ? S Sep15 0:04 pgpool: postgres db_name_live Server01(56880) idle in transaction postgres 32677 0.0 0.0 486208 28980 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.35(58668) idle in transaction postgres 32769 0.0 0.0 487940 81896 ? Ss Sep15 0:01 postgres: postgres db_name_live 1.1.1.35(58786) idle in transaction postgres 32775 0.0 0.1 499508 134792 ? Ss Sep15 0:05 postgres: postgres db_name_live 1.1.1.35(58822) idle in transaction root 53601 0.0 0.0 98848 9048 ? S Sep15 0:04 pgpool: postgres db_name_live Server01(46060) idle in transaction postgres 54257 0.0 0.0 487788 30208 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.35(58510) idle in transaction postgres 54329 0.0 0.0 488108 36640 ? Ss Sep15 0:01 postgres: postgres db_name_live 1.1.1.35(58560) idle in transaction postgres 54331 0.0 0.0 486760 30324 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.35(58572) idle in transaction postgres 54335 0.0 0.0 488228 28644 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.35(58598) idle in transaction postgres 64243 0.0 0.0 486388 24864 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.35(42714) idle in transaction postgres 82790 0.0 0.0 486352 27296 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.39(58613) idle in transaction postgres 107131 0.0 0.0 486224 26328 ? Ss Sep15 0:00 postgres: postgres db_name_live 1.1.1.35(46824) idle in transaction --> select * from pg_stat_activity where state = 'idle in transaction'; <-- 25925;"db_name_live";32677;10;"postgres";"";"1.1.1.35";"";58668;"2016-09-15 18:17:51.721971+02";"2016-09-16 08:30:39.482921+02";"2016-09-16 08:30:39.484771+02";"2016-09-16 08:30:39.484862+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1074"."retailer"') AND c.relpersistence = 'u'" 25925;"db_name_live";32769;10;"postgres";"";"1.1.1.35";"";58786;"2016-09-15 18:17:57.909161+02";"2016-09-16 04:48:39.311386+02";"2016-09-16 04:48:39.31384+02";"2016-09-16 04:48:39.313901+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1163"."retailer"') AND c.relpersistence = 'u'" 25925;"db_name_live";32775;10;"postgres";"";"1.1.1.35";"";58822;"2016-09-15 18:17:57.917084+02";"2016-09-15 20:05:59.153106+02";"2016-09-15 20:05:59.157015+02";"2016-09-15 20:05:59.157068+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1128"."store"') AND c.relpersistence = 'u'" 25925;"db_name_live";64243;10;"postgres";"";"1.1.1.35";"";42714;"2016-09-15 19:50:00.113876+02";"2016-09-15 20:27:09.970091+02";"2016-09-15 20:27:09.975386+02";"2016-09-15 20:27:09.975442+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1230"."store_opening_hours"') AND c.relpersistence = 'u'" 25925;"db_name_live";82790;10;"postgres";"";"1.1.1.39";"";58613;"2016-09-15 20:49:52.829227+02";"2016-09-15 20:59:50.715979+02";"2016-09-15 20:59:50.720067+02";"2016-09-15 20:59:50.720116+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1120"."store"') AND c.relpersistence = 'u'" 25925;"db_name_live";107131;10;"postgres";"";"1.1.1.35";"";46824;"2016-09-15 22:10:00.057738+02";"2016-09-15 22:48:05.83686+02";"2016-09-15 22:48:05.841564+02";"2016-09-15 22:48:05.841647+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1041"."store"') AND c.relpersistence = 'u'" 25925;"db_name_live";54257;10;"postgres";"";"1.1.1.35";"";58510;"2016-09-15 19:21:58.43688+02";"2016-09-15 22:05:49.531102+02";"2016-09-15 22:05:49.536976+02";"2016-09-15 22:05:49.537067+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1041"."store_opening_hours"') AND c.relpersistence = 'u'" 25925;"db_name_live";20680;10;"postgres";"";"1.1.1.35";"";47438;"2016-09-16 01:30:00.057351+02";"2016-09-16 03:34:53.785033+02";"2016-09-16 03:34:53.787619+02";"2016-09-16 03:34:53.787689+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1151"."retailer"') AND c.relpersistence = 'u'" 25925;"db_name_live";29836;10;"postgres";"";"1.1.1.35";"";60228;"2016-09-16 02:00:00.07892+02";"2016-09-16 03:22:40.961839+02";"2016-09-16 03:22:40.965557+02";"2016-09-16 03:22:40.965623+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1163"."store"') AND c.relpersistence = 'u'" 25925;"db_name_live";54329;10;"postgres";"";"1.1.1.35";"";58560;"2016-09-15 19:22:02.257087+02";"2016-09-15 21:21:38.123049+02";"2016-09-15 21:21:38.124774+02";"2016-09-15 21:21:38.124875+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1120"."retailer"') AND c.relpersistence = 'u'" 25925;"db_name_live";54331;10;"postgres";"";"1.1.1.35";"";58572;"2016-09-15 19:22:02.260368+02";"2016-09-15 20:45:49.160629+02";"2016-09-15 20:45:49.174832+02";"2016-09-15 20:45:49.174877+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1151"."store_opening_hours"') AND c.relpersistence = 'u'" 25925;"db_name_live";54335;10;"postgres";"";"1.1.1.35";"";58598;"2016-09-15 19:22:02.280404+02";"2016-09-15 20:11:01.433778+02";"2016-09-15 20:11:01.436023+02";"2016-09-15 20:11:01.436102+02";f;"idle in transaction";;;"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.oid = to_regclass('"tenant_1049"."retailer"') AND c.relpersistence = 'u'" |
|
|
Do you know how to reproduce the problem? |
|
|
I think it has something to do with the Pgpool transaction delay checks. The problem reproduces by it self, till now I don't know how to provoke it. |
|
|
Do you use extended protocol? What kind of application language do you use? All the queries are related to temp table checking. Can you try with check_temp_table = off and see if the same problem occurs? |
|
|
JAVA and Wildfly Application Server Will change this setting for testing |
|
|
I think why pg_stat_activity show that is explained in the FAQ: http://pgpool.net/mediawiki/index.php/FAQ#When_I_check_pg_stat_activity_view.2C_I_see_a_query_like_.22SELECT_count.28.2A.29_FROM_pg_catalog.pg_class_AS_c_WHERE_c.oid_.3D_pgpool_regclass.28.27pgbench_accounts.27.29_AND_c.relpersistence_.3D_.27u.27.22_in_active_state_for_very_long_time._Why.3F And why there are so many connections to Pgpoll-II remaining is, your Java frame work has a function of connection pooling. From Pgpool-II's point of view, the client does not disconnect to Pgpool-II. Please trun off the connection pooling of Java or set client_idle_limit in pgpool.conf to other than 0 (say, 30). |
|
|
Over 1 month there's no action from the reporter. Issue closed. |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2016-09-16 00:00 | tschmidt82 | New Issue | |
| 2016-09-16 00:00 | tschmidt82 | File Added: pgpool.zip | |
| 2016-09-16 14:14 | t-ishii | Note Added: 0001067 | |
| 2016-09-16 14:14 | t-ishii | Note Edited: 0001067 | |
| 2016-09-16 16:34 | tschmidt82 | Note Added: 0001069 | |
| 2016-09-21 16:36 | t-ishii | Assigned To | => t-ishii |
| 2016-09-21 16:36 | t-ishii | Status | new => assigned |
| 2016-09-23 15:29 | t-ishii | Note Added: 0001083 | |
| 2016-09-23 15:30 | t-ishii | Status | assigned => feedback |
| 2016-09-26 18:59 | tschmidt82 | Note Added: 0001085 | |
| 2016-09-26 18:59 | tschmidt82 | Status | feedback => assigned |
| 2016-09-28 11:57 | t-ishii | Note Added: 0001101 | |
| 2016-09-28 11:57 | t-ishii | Status | assigned => feedback |
| 2016-11-09 22:48 | tschmidt82 | Note Added: 0001155 | |
| 2016-11-09 22:48 | tschmidt82 | Status | feedback => assigned |
| 2016-11-10 14:21 | t-ishii | Note Added: 0001156 | |
| 2016-11-10 14:21 | t-ishii | Status | assigned => feedback |
| 2016-12-20 14:02 | t-ishii | Note Added: 0001239 | |
| 2016-12-20 14:02 | t-ishii | Status | feedback => closed |
