[pgpool-general: 5284] PGPool (3.5.5/3.6.1) hangs on connection in Master/Slave mode
Michael Musenbrock
redeamer at gmx.net
Tue Jan 31 03:58:06 JST 2017
Hi @all,
hopefully someone can shed some light on our problem!
We have a setup with three nodes in Master/Slave mode with slony in background.
System is a RHEL 7.3 with PostgreSQL 9.2.19 and Slony 2.1.4. (built with data from
pgrmps). For debugging reasons, only the master is active, with no configured slaves.
We upgraded from PGPool version 3.4.3 to 3.5.5. Starting with the upgrade our application
(Java with Hibernate (tested with 4.3.11 and 4.2.7)) can't establish a connection via
PGPool to our database.
I also tried a connection via the simple pgpoolbug application provided in Bug 167 [1],
which can't connect. If pgpoolbug connects to postgresql directly, everything works
fine. If I disable the master_slave_mode, the connection works as well. The output
of pgpoolbug is attached as pgpoolbug_jar.out [2].
Additionally find the debug-output of pgpool attached [3] while pgpoolbug tried to connect.
Same behavior for PGPool 3.5.5 and 3.6.1.
Thanks in advance for any help
please let me know, if I can provide you more information
Regards Michael
[1] http://www.pgpool.net/mantisbt/view.php?id=167
[2] pgpoolbug_jar.out: stdout of hanging connection debug jar
[3] pgpoold.out: stdout/stderr of pgpool while pgpoolbug.jar tries to connect
-------------- next part --------------
Initialising Hibernate
Jan 30, 2017 7:50:27 PM org.hibernate.annotations.common.reflection.java.JavaReflectionManager <clinit>
INFO: HCANN000001: Hibernate Commons Annotations {4.0.4.Final}
Jan 30, 2017 7:50:27 PM org.hibernate.Version logVersion
INFO: HHH000412: Hibernate Core {4.3.4.Final}
Jan 30, 2017 7:50:27 PM org.hibernate.cfg.Environment <clinit>
INFO: HHH000206: hibernate.properties not found
Jan 30, 2017 7:50:27 PM org.hibernate.cfg.Environment buildBytecodeProvider
INFO: HHH000021: Bytecode provider name : javassist
Jan 30, 2017 7:50:27 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl configure
WARN: HHH000402: Using Hibernate built-in connection pool (not for production use!)
Jan 30, 2017 7:50:27 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator
INFO: HHH000401: using driver [org.postgresql.Driver] at URL [jdbc:postgresql://10.200.1.30:9999/tmcs?loglevel=2]
Jan 30, 2017 7:50:27 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator
INFO: HHH000046: Connection properties: {user=tmcs, password=****}
Jan 30, 2017 7:50:27 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator
INFO: HHH000006: Autocommit mode: false
Jan 30, 2017 7:50:27 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl configure
INFO: HHH000115: Hibernate connection pool size: 10 (min=1)
19:50:27.843 (1) PostgreSQL 9.4 JDBC4.1 (build 1202)
19:50:27.851 (1) Trying to establish a protocol version 3 connection to 10.200.1.30:9999
19:50:27.861 (1) Receive Buffer Size is 186240
19:50:27.861 (1) Send Buffer Size is 23040
19:50:27.863 (1) FE=> StartupPacket(user=tmcs, database=tmcs, client_encoding=UTF8, DateStyle=ISO, TimeZone=Europe/Vienna, extra_float_digits=2)
19:50:27.876 (1) <=BE AuthenticationOk
19:50:27.882 (1) <=BE ParameterStatus(application_name = )
19:50:27.883 (1) <=BE ParameterStatus(client_encoding = UTF8)
19:50:27.883 (1) <=BE ParameterStatus(DateStyle = ISO, DMY)
19:50:27.883 (1) <=BE ParameterStatus(integer_datetimes = on)
19:50:27.883 (1) <=BE ParameterStatus(IntervalStyle = postgres)
19:50:27.883 (1) <=BE ParameterStatus(is_superuser = on)
19:50:27.883 (1) <=BE ParameterStatus(server_encoding = UTF8)
19:50:27.883 (1) <=BE ParameterStatus(server_version = 9.2.19)
19:50:27.883 (1) <=BE ParameterStatus(session_authorization = tmcs)
19:50:27.883 (1) <=BE ParameterStatus(standard_conforming_strings = on)
19:50:27.883 (1) <=BE ParameterStatus(TimeZone = Europe/Vienna)
19:50:27.883 (1) <=BE BackendKeyData(pid=12564,ckey=1546187178)
19:50:27.883 (1) <=BE ReadyForQuery(I)
19:50:27.885 (1) simple execute, handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler at 1786dec2, maxRows=0, fetchSize=0, flags=23
19:50:27.886 (1) FE=> Parse(stmt=null,query="SET extra_float_digits = 3",oids={})
19:50:27.886 (1) FE=> Bind(stmt=null,portal=null)
19:50:27.886 (1) FE=> Execute(portal=null,limit=1)
19:50:27.886 (1) FE=> Sync
19:50:27.889 (1) <=BE ParseComplete [null]
-------------- next part --------------
2017-01-30 18:50:22: pid 12497: DEBUG: pool_coninfo_size: num_init_children (4) * max_pool (16) * MAX_NUM_BACKENDS (128) * sizeof(ConnectionInfo) (136) = 1114112 bytes requested for shared memory
2017-01-30 18:50:22: pid 12497: LOCATION: pool_process_context.c:109
2017-01-30 18:50:22: pid 12497: DEBUG: ProcessInfo: num_init_children (4) * sizeof(ProcessInfo) (32) = 128 bytes requested for shared memory
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:2922
2017-01-30 18:50:22: pid 12497: DEBUG: Request info are: sizeof(POOL_REQUEST_INFO) 5264 bytes requested for shared memory
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:2937
2017-01-30 18:50:22: pid 12497: DEBUG: Recovery management area: sizeof(int) 4 bytes requested for shared memory
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:2960
2017-01-30 18:50:22: pid 12497: LOG: Setting up socket for 0.0.0.0:9999
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:826
2017-01-30 18:50:22: pid 12497: LOG: Setting up socket for :::9999
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:826
2017-01-30 18:50:22: pid 12498: DEBUG: initializing backend status
2017-01-30 18:50:22: pid 12498: LOCATION: child.c:1778
2017-01-30 18:50:22: pid 12499: DEBUG: initializing backend status
2017-01-30 18:50:22: pid 12499: LOCATION: child.c:1778
2017-01-30 18:50:22: pid 12500: DEBUG: initializing backend status
2017-01-30 18:50:22: pid 12500: LOCATION: child.c:1778
2017-01-30 18:50:22: pid 12501: DEBUG: initializing backend status
2017-01-30 18:50:22: pid 12501: LOCATION: child.c:1778
2017-01-30 18:50:22: pid 12502: DEBUG: I am PCP child with pid:12502
2017-01-30 18:50:22: pid 12502: LOCATION: pcp_child.c:105
2017-01-30 18:50:22: pid 12497: LOG: pgpool-II successfully started. version 3.5.5 (ekieboshi)
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:392
2017-01-30 18:50:22: pid 12497: DEBUG: find_primary_node: not in streaming replication mode
2017-01-30 18:50:22: pid 12497: LOCATION: pgpool_main.c:2783
2017-01-30 18:50:22: pid 12503: DEBUG: I am 12503
2017-01-30 18:50:22: pid 12503: LOCATION: pool_worker_child.c:100
2017-01-30 18:50:22: pid 12503: DEBUG: initializing backend status
2017-01-30 18:50:22: pid 12503: LOCATION: child.c:1778
2017-01-30 18:50:27: pid 12501: DEBUG: I am 12501 accept fd 6
2017-01-30 18:50:27: pid 12501: LOCATION: child.c:2116
2017-01-30 18:50:27: pid 12501: LOG: new connection received
2017-01-30 18:50:27: pid 12501: DETAIL: connecting host=10.0.1.183 port=52866
2017-01-30 18:50:27: pid 12501: LOCATION: child.c:2129
2017-01-30 18:50:27: pid 12501: DEBUG: reading startup packet
2017-01-30 18:50:27: pid 12501: DETAIL: Protocol Major: 3 Minor: 0 database: XXXX user: XXXX
2017-01-30 18:50:27: pid 12501: LOCATION: child.c:620
2017-01-30 18:50:27: pid 12501: DEBUG: creating new connection to backend
2017-01-30 18:50:27: pid 12501: DETAIL: connecting 0 backend
2017-01-30 18:50:27: pid 12501: LOCATION: pool_connection_pool.c:829
2017-01-30 18:50:27: pid 12501: DEBUG: attempting to negotiate a secure connection
2017-01-30 18:50:27: pid 12501: DETAIL: sending client->server SSL request
2017-01-30 18:50:27: pid 12501: LOCATION: pool_ssl.c:77
2017-01-30 18:50:27: pid 12501: DEBUG: pool_read: read 1 bytes from backend 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_stream.c:190
2017-01-30 18:50:27: pid 12501: DEBUG: attempting to negotiate a secure connection
2017-01-30 18:50:27: pid 12501: DETAIL: client->server SSL response: S
2017-01-30 18:50:27: pid 12501: LOCATION: pool_ssl.c:89
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: slot: 0 length: 8
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1109
2017-01-30 18:50:27: pid 12501: DEBUG: authentication backend
2017-01-30 18:50:27: pid 12501: DETAIL: auth kind:0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:144
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 22
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"application_name" value:""
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 25
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"client_encoding" value:"UTF8"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 23
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"DateStyle" value:"ISO, DMY"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 25
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"integer_datetimes" value:"on"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 27
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"IntervalStyle" value:"postgres"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 20
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"is_superuser" value:"on"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 25
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"server_encoding" value:"UTF8"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 26
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"server_version" value:"9.2.19"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 31
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"session_authorization" value:"XXXX"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 35
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"standard_conforming_strings" value:"on"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: master slot: 0 length: 27
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1163
2017-01-30 18:50:27: pid 12501: DEBUG: process parameter status
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 name:"TimeZone" value:"Europe/Vienna"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:937
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: slot: 0 length: 12
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1109
2017-01-30 18:50:27: pid 12501: DEBUG: authentication backend
2017-01-30 18:50:27: pid 12501: DETAIL: cp->info[i]:0x7feb67ea8000 pid:12564
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:393
2017-01-30 18:50:27: pid 12501: DEBUG: sending backend key data
2017-01-30 18:50:27: pid 12501: DETAIL: send pid 12564 to frontend
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:521
2017-01-30 18:50:27: pid 12501: DEBUG: selecting load balance node
2017-01-30 18:50:27: pid 12501: DETAIL: selected backend id is 0
2017-01-30 18:50:27: pid 12501: LOCATION: child.c:1739
2017-01-30 18:50:27: pid 12501: DEBUG: initializing session context
2017-01-30 18:50:27: pid 12501: DETAIL: selected load balancing node: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:105
2017-01-30 18:50:27: pid 12501: DEBUG: session context: unsetting query in progress. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:225
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing transaction isolation. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:737
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing writing transaction. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:571
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing failed transaction. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:600
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing failed transaction. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:630
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing skip reading from backends. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:256
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing ignore till sync. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:316
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: reading backend data packet kind
2017-01-30 18:50:27: pid 12501: DETAIL: master node id: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3270
2017-01-30 18:50:27: pid 12501: DEBUG: reading backend data packet kind
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 of 1 kind = 'Z'
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3388
2017-01-30 18:50:27: pid 12501: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3404
2017-01-30 18:50:27: pid 12501: DEBUG: processing backend response
2017-01-30 18:50:27: pid 12501: DETAIL: received kind 'Z'(5a) from backend
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:2429
2017-01-30 18:50:27: pid 12501: DEBUG: processing backend response
2017-01-30 18:50:27: pid 12501: DETAIL: Ready For Query received
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:2447
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing ignore till sync. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:316
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 0 doing extended query: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: reading message length
2017-01-30 18:50:27: pid 12501: DETAIL: slot: 0 length: 5
2017-01-30 18:50:27: pid 12501: LOCATION: pool_auth.c:1109
2017-01-30 18:50:27: pid 12501: DEBUG: processing ReadyForQuery
2017-01-30 18:50:27: pid 12501: DETAIL: transaction state '
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:1616
2017-01-30 18:50:27: pid 12501: DEBUG: processing frontend response
2017-01-30 18:50:27: pid 12501: DETAIL: received kind 'P'(50) from frontend
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:2192
2017-01-30 18:50:27: pid 12501: DEBUG: session context: clearing doing extended query messaging. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:286
2017-01-30 18:50:27: pid 12501: DEBUG: session context: setting doing extended query messaging. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:275
2017-01-30 18:50:27: pid 12501: DEBUG: Parse: statement name <>
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:821
2017-01-30 18:50:27: pid 12501: DEBUG: session context: setting query in progress. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:214
2017-01-30 18:50:27: pid 12501: DEBUG: decide where to send the queries
2017-01-30 18:50:27: pid 12501: DETAIL: destination = 3 for query= "SET extra_float_digits = 3"
2017-01-30 18:50:27: pid 12501: LOCATION: pool_query_context.c:387
2017-01-30 18:50:27: pid 12501: DEBUG: Parse: waiting for master completing the query
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:1068
2017-01-30 18:50:27: pid 12501: LOG: DB node id: 0 backend pid: 12564 statement: Parse: SET extra_float_digits = 3
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:2970
2017-01-30 18:50:27: pid 12501: DEBUG: pool_send_and_wait: pool_set_sync_map: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_query_context.c:871
2017-01-30 18:50:27: pid 12501: DEBUG: pool_write: to backend: 0 kind:P
2017-01-30 18:50:27: pid 12501: LOCATION: pool_stream.c:431
2017-01-30 18:50:27: pid 12501: DEBUG: pool_write: to backend: 0 kind:H
2017-01-30 18:50:27: pid 12501: LOCATION: pool_stream.c:431
2017-01-30 18:50:27: pid 12501: DEBUG: waiting for query response
2017-01-30 18:50:27: pid 12501: DETAIL: waiting for backend:0 to complete the query
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:484
2017-01-30 18:50:27: pid 12501: DEBUG: detect error: kind: 1
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:4205
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: reading backend data packet kind
2017-01-30 18:50:27: pid 12501: DETAIL: master node id: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3270
2017-01-30 18:50:27: pid 12501: DEBUG: reading backend data packet kind
2017-01-30 18:50:27: pid 12501: DETAIL: backend:0 of 1 kind = '1'
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3388
2017-01-30 18:50:27: pid 12501: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3404
2017-01-30 18:50:27: pid 12501: DEBUG: processing backend response
2017-01-30 18:50:27: pid 12501: DETAIL: received kind '1'(31) from backend
2017-01-30 18:50:27: pid 12501: LOCATION: pool_proto_modules.c:2429
2017-01-30 18:50:27: pid 12501: DEBUG: called by pool_add_sent_message: sent message: address: 0x19a59b0 kind: P name: ==
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:442
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: SimpleForwardToFrontend: packet:1 length:0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:808
2017-01-30 18:50:27: pid 12501: DEBUG: session context: setting command success. DONE
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:747
2017-01-30 18:50:27: pid 12501: DEBUG: pool_use_sync_map: we cannot use sync map because STREAM: 0 query in progress: 1 doing extended query: 1
2017-01-30 18:50:27: pid 12501: LOCATION: pool_session_context.c:975
2017-01-30 18:50:27: pid 12501: DEBUG: reading backend data packet kind
2017-01-30 18:50:27: pid 12501: DETAIL: master node id: 0
2017-01-30 18:50:27: pid 12501: LOCATION: pool_process_query.c:3270
2017-01-30 18:50:41: pid 12502: DEBUG: PCP child receives shutdown request signal 2, Forwarding to all children
2017-01-30 18:50:41: pid 12502: LOCATION: pcp_child.c:358
2017-01-30 18:50:41: pid 12501: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12501: LOCATION: child.c:923
2017-01-30 18:50:41: pid 12500: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12500: LOCATION: child.c:923
2017-01-30 18:50:41: pid 12499: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12499: LOCATION: child.c:923
2017-01-30 18:50:41: pid 12497: LOG: received fast shutdown request
2017-01-30 18:50:41: pid 12497: LOCATION: pgpool_main.c:1367
2017-01-30 18:50:41: pid 12502: DEBUG: PCP child receives fast shutdown request
2017-01-30 18:50:41: pid 12502: LOCATION: pcp_child.c:373
2017-01-30 18:50:41: pid 12501: DEBUG: pool_write: to backend: 0 kind:X
2017-01-30 18:50:41: pid 12501: LOCATION: pool_stream.c:431
2017-01-30 18:50:41: pid 12497: LOG: shutdown request. closing listen socket
2017-01-30 18:50:41: pid 12497: LOCATION: pgpool_main.c:1386
2017-01-30 18:50:41: pid 12499: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12499: LOCATION: child.c:923
2017-01-30 18:50:41: pid 12500: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12500: LOCATION: child.c:923
2017-01-30 18:50:41: pid 12501: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12501: LOCATION: child.c:923
2017-01-30 18:50:41: pid 12502: DEBUG: PCP child receives shutdown request signal 2, Forwarding to all children
2017-01-30 18:50:41: pid 12502: LOCATION: pcp_child.c:358
2017-01-30 18:50:41: pid 12502: DEBUG: PCP child receives fast shutdown request
2017-01-30 18:50:41: pid 12502: LOCATION: pcp_child.c:373
2017-01-30 18:50:41: pid 12498: LOG: child process received shutdown request signal 2
2017-01-30 18:50:41: pid 12498: LOCATION: child.c:923
More information about the pgpool-general
mailing list