View Issue Details

IDProjectCategoryView StatusLast Update
0000376Pgpool-IIBugpublic2018-01-24 08:36
ReporteryremmetAssigned Tot-ishii 
PrioritynormalSeverityminorReproducibilityhave not tried
Status resolvedResolutionopen 
PlatformOpenstack/KVMOSUbuntuOS Version14.04.1
Product Version3.7.1 
Target Version3.7.2Fixed in Version 
Summary0000376: child process was terminated by segmentation fault
DescriptionI'm getting the following error every time I execute a command.

2018-01-11 15:41:36 [No Connection] MAIN[23999] [No Connection]@[No Connection]: DEBUG: reaper handler
2018-01-11 15:41:36 [No Connection] MAIN[23999] [No Connection]@[No Connection]: WARNING: child process with pid: 24019 was terminated by segmentation fault
2018-01-11 15:41:36 [No Connection] MAIN[23999] [No Connection]@[No Connection]: LOG: fork a new child process with pid: 24204
2018-01-11 15:41:36 [No Connection] MAIN[23999] [No Connection]@[No Connection]: DEBUG: reaper handler: exiting normally
2018-01-11 15:41:36 [No Connection] CHILD[24204] [No Connection]@[No Connection]: DEBUG: initializing backend status

I'm using PostgreSQL-9.5.1 with streaming replication.
TagsNo tags attached.

Activities

yremmet

2018-01-12 17:48

reporter  

pgpool.conf (1,697 bytes)

yremmet

2018-01-15 16:43

reporter   ~0001892

I added the full log file.

yremmet

2018-01-15 16:51

reporter   ~0001893

The file was to big.

t-ishii

2018-01-16 15:59

developer   ~0001895

Please provide a stack trace.

BTW, your pgpool.conf lacks definitions of weight parameters. i.e. backend_weight0 etc.

yremmet

2018-01-16 21:27

reporter   ~0001896

Hi,
could you tell me how I get a stack trace of the failing process? I don't know gdb so well.

I found out that the error only occurs when pgpool is started with the --debug flag.

t-ishii

2018-01-17 10:18

developer   ~0001899

That depends on how you install/start Pgpool-II. Please provide the info.

yremmet

2018-01-18 01:11

reporter   ~0001900

I compile pgpool from source and its run by the attached control script.

ctl (1,201 bytes)
#!/bin/bash

set -e # exit immediately if a simple command exits with a non-zero status
set -u # report the usage of uninitialized variables

source /var/vcap/jobs/pgpool/helpers/ctl_setup.sh 'pgpool'

export JOBNAME=pgpool
export LANG=en_US.UTF-8
export RUN_DIR=/var/vcap/sys/run/$JOB_NAME
export LOG_DIR=/var/vcap/sys/log/$JOB_NAME
export TMP_DIR=/var/vcap/sys/tmp/$JOB_NAME
export STORE_DIR=/var/vcap/store/$JOB_NAME
PIDFILE=$RUN_DIR/pgpool.pid

case $1 in

  start)
    pid_guard $PIDFILE $JOB_NAME

    # (possibly) create an empty pgpool passwd authdb
    touch ${JOB_DIR}/config/passwd

    chmod +x ${JOB_DIR}/config/failover.sh

    # run pgpool
    chpst -u vcap:vcap pgpool -n  \
         -f ${JOB_DIR}/config/pgpool.conf \
         -F ${JOB_DIR}/config/pcp.conf \
         -a ${JOB_DIR}/config/hba.conf \
         >>$LOG_DIR/$JOB_NAME.log 2>&1 &

    ;;

  stop)
    chpst -u vcap:vcap pgpool \
         -f ${JOB_DIR}/config/pgpool.conf \
         -F ${JOB_DIR}/config/pcp.conf \
         -a ${JOB_DIR}/config/hba.conf \
         -m fast stop \
         >>$LOG_DIR/$JOB_NAME.log 2>&1 &
    #kill_and_wait $PIDFILE

    ;;
  *)
    echo "Usage: pgpool_ctl {start|stop}"

    ;;

esac
exit 0
ctl (1,201 bytes)

t-ishii

2018-01-18 07:46

developer   ~0001901

Probably just add following line to "ctl" is enough.
ulimit -c unlimited

Pgpool-II will produce a core file as soon as it segfaults. Then you can attach gdb to the core file like:

gdb path-to-pgpool-command core-file
bt

This will produce a stack trace.

jhiemer

2018-01-23 16:20

reporter   ~0001907

Hi t-ishii,
on behalf of yremmet I have collected some logs and tried to get some data regarding the segmentation fault. What I was able to produce are the following files:

- plain-connect-no-gdb-attached.txt opening a connection to the database, which directly results in the segmentation fault as you can see from the logs.
- plain-connection-gdb-attached.txt opening a connection to the database, which does not result in a segmentation fault.

For both cases it is not possible to connect to the instances. The error is always:

"server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request."

Attached is also the gdb log.

Directly connection to both postgres instances works flawlessly.

plain-connection-gdb-attached.txt (28,210 bytes)
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  I am 5425 accept fd 6
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading startup packet
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  Protocol Major: 1234 Minor: 5679 database:  user:
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  selecting backend connection
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  SSLRequest from client
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  SSL is requested but SSL support is not available
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:N po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading startup packet
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  application_name: Postico 1.3.1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading startup packet
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  Protocol Major: 3 Minor: 0 database: admin user: admin
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  creating new connection to backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  connecting 0 backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  creating new connection to backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  connecting 1 backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  SSL is requested but SSL support is not available
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 122
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  SSL is requested but SSL support is not available
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 122
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_read: read 13 bytes from backend 0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_read: read 13 bytes from backend 1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  slot: 0 length: 12
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  slot: 1 length: 12
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  auth kind:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  trying md5 authentication
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:R po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:9
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 13
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  performing md5 authentication
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  DB node id: 0 salt: affed124
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to backend: 0 kind:p
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 41
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_read: read 332 bytes from backend 0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:R po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 9
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  trying md5 authentication
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  performing md5 authentication
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  DB node id: 1 salt: 5b36fec6
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to backend: 1 kind:p
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 41
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_read: read 332 bytes from backend 1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 35
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 35
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"application_name" value:"Postico 1.3.1"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"application_name" value:"Postico 1.3.1"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:31 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 36
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 28
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 28
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"client_encoding" value:"UNICODE"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"client_encoding" value:"UNICODE"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:24 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 29
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 23
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 23
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"DateStyle" value:"ISO, MDY"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"DateStyle" value:"ISO, MDY"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:19 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 24
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 25
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 25
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"integer_datetimes" value:"on"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"integer_datetimes" value:"on"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:21 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 26
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 27
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 27
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"IntervalStyle" value:"postgres"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"IntervalStyle" value:"postgres"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:23 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 28
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 20
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 20
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"is_superuser" value:"on"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"is_superuser" value:"on"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:16 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 21
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 25
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 25
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"server_encoding" value:"UTF8"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"server_encoding" value:"UTF8"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:21 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 26
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 26
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 26
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"server_version" value:"9.5.10"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"server_version" value:"9.5.10"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:22 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 27
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 32
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 32
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"session_authorization" value:"admin"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"session_authorization" value:"admin"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:28 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 33
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 35
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 35
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"standard_conforming_strings" value:"on"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"standard_conforming_strings" value:"on"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:31 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 36
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 17
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 17
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"TimeZone" value:"GMT"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"TimeZone" value:"GMT"
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:13 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 18
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  slot: 0 length: 12
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  slot: 1 length: 12
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  cp->info[i]:0x7f9330359000 pid:5827
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  cp->info[i]:0x7f9330359088 pid:5548
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:K po:0
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  sending backend key data
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DETAIL:  send pid 5548 to frontend
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:5
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:9
2018-01-23 07:13:33 [No Connection] CHILD[5425] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 13
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  initializing session context
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  selected load balancing node: 0
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: unsetting query in progress. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing transaction isolation. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing writing transaction. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing failed transaction. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing failed transaction. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing skip reading from backends. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing ignore till sync. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  master node id: 0
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  backend:0 kind:'Z'
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  backend:0 of 2 kind = 'Z'
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  backend:1 kind:'Z'
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  backend:1 of 2 kind = 'Z'
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  read_kind_from_backend max_count:2.000000 num_executed_nodes:2
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  processing backend response
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  received kind 'Z'(5a) from backend
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  processing backend response
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  Ready For Query received
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing ignore till sync. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading message length
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  slot: 0 length: 5
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  reading message length
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  slot: 1 length: 5
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  processing ReadyForQuery
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  transaction state '
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  processing ReadyForQuery
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  transaction state 'I'(49)
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  pool_write: to frontend: kind:Z po:0
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  pool_write: to frontend: kind:I po:5
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  pool_flush_it: flush size: 6
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  processing frontend response
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DETAIL:  received kind 'Q'(51) from frontend
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: clearing doing extended query messaging. DONE
2018-01-23 07:13:33 Postico 1.3.1 CHILD[5425] admin@admin: DEBUG:  session context: setting query in progress. DONE
plain-connect-no-gdb-attached.txt (28,832 bytes)
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  I am 5140 accept fd 6
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading startup packet
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  Protocol Major: 1234 Minor: 5679 database:  user:
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  selecting backend connection
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  SSLRequest from client
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  SSL is requested but SSL support is not available
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:N po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading startup packet
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  application_name: Postico 1.3.1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading startup packet
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  Protocol Major: 3 Minor: 0 database: admin user: admin
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  creating new connection to backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  connecting 0 backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  creating new connection to backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  connecting 1 backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  SSL is requested but SSL support is not available
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 122
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  SSL is requested but SSL support is not available
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 122
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_read: read 13 bytes from backend 0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_read: read 13 bytes from backend 1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  slot: 0 length: 12
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  slot: 1 length: 12
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  auth kind:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  trying md5 authentication
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:R po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:9
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 13
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  performing md5 authentication
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  DB node id: 0 salt: 43dc3260
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to backend: 0 kind:p
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 41
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_read: read 332 bytes from backend 0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:R po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 9
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  trying md5 authentication
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  performing md5 authentication
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  DB node id: 1 salt: 842af7fe
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to backend: 1 kind:p
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 41
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_read: read 332 bytes from backend 1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 35
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 35
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"application_name" value:"Postico 1.3.1"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"application_name" value:"Postico 1.3.1"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:31 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 36
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 28
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 28
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"client_encoding" value:"UNICODE"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"client_encoding" value:"UNICODE"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:24 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 29
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 23
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 23
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"DateStyle" value:"ISO, MDY"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"DateStyle" value:"ISO, MDY"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:19 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 24
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 25
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 25
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"integer_datetimes" value:"on"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"integer_datetimes" value:"on"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:21 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 26
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 27
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 27
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"IntervalStyle" value:"postgres"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"IntervalStyle" value:"postgres"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:23 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 28
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 20
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 20
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"is_superuser" value:"on"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"is_superuser" value:"on"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:16 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 21
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 25
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 25
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"server_encoding" value:"UTF8"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"server_encoding" value:"UTF8"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:21 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 26
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 26
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 26
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"server_version" value:"9.5.10"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"server_version" value:"9.5.10"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:22 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 27
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 32
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 32
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"session_authorization" value:"admin"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"session_authorization" value:"admin"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:28 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 33
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 35
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 35
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"standard_conforming_strings" value:"on"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"standard_conforming_strings" value:"on"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:31 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 36
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:S po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 0 length: 17
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  master slot: 1 length: 17
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:0 name:"TimeZone" value:"GMT"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  process parameter status
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  backend:1 name:"TimeZone" value:"GMT"
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:13 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 18
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  slot: 0 length: 12
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  reading message length
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  slot: 1 length: 12
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  cp->info[i]:0x7f9330436000 pid:5816
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  authentication backend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  cp->info[i]:0x7f9330436088 pid:5545
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: kind:K po:0
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  sending backend key data
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DETAIL:  send pid 5545 to frontend
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:5
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_write: to frontend: length:4 po:9
2018-01-23 07:12:34 [No Connection] CHILD[5140] [No Connection]@[No Connection]: DEBUG:  pool_flush_it: flush size: 13
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  initializing session context
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  selected load balancing node: 0
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: unsetting query in progress. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing transaction isolation. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing writing transaction. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing failed transaction. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing failed transaction. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing skip reading from backends. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing ignore till sync. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  master node id: 0
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  backend:0 kind:'Z'
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  backend:0 of 2 kind = 'Z'
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  backend:1 kind:'Z'
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading backend data packet kind
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  backend:1 of 2 kind = 'Z'
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  read_kind_from_backend max_count:2.000000 num_executed_nodes:2
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  processing backend response
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  received kind 'Z'(5a) from backend
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  processing backend response
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  Ready For Query received
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing ignore till sync. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading message length
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  slot: 0 length: 5
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  reading message length
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  slot: 1 length: 5
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  processing ReadyForQuery
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  transaction state '
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  processing ReadyForQuery
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  transaction state 'I'(49)
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  pool_write: to frontend: kind:Z po:0
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  pool_write: to frontend: length:4 po:1
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  pool_write: to frontend: kind:I po:5
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  pool_flush_it: flush size: 6
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  processing frontend response
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DETAIL:  received kind 'Q'(51) from frontend
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: clearing doing extended query messaging. DONE
2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140] admin@admin: DEBUG:  session context: setting query in progress. DONE
2018-01-23 07:12:34 [No Connection] MAIN[5121] [No Connection]@[No Connection]: DEBUG:  reaper handler
2018-01-23 07:12:34 [No Connection] MAIN[5121] [No Connection]@[No Connection]: WARNING:  child process with pid: 5140 was terminated by segmentation fault
2018-01-23 07:12:34 [No Connection] MAIN[5121] [No Connection]@[No Connection]: LOG:  fork a new child process with pid: 5817
2018-01-23 07:12:34 [No Connection] MAIN[5121] [No Connection]@[No Connection]: DEBUG:  reaper handler: exiting normally
2018-01-23 07:12:34 [No Connection] CHILD[5817] [No Connection]@[No Connection]: DEBUG:  initializing backend status
gdb-logs.txt (2,069 bytes)
postgres/0767cb6a-3deb-41fe-8a93-e6a01d373d48:/var/vcap/bosh_ssh/bosh_363bc7bd29cf4c0# gdb
GNU gdb (Ubuntu 7.7.1-0ubuntu5~14.04.3) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
(gdb) attach 5121
Attaching to process 5121
Reading symbols from /var/vcap/data/packages/pgpool2/a02f2cb3958463f838e8eb42a8b20812f376541c/bin/pgpool...done.
Reading symbols from /var/vcap/packages/postgres/lib/libpq.so.5...(no debugging symbols found)...done.
Loaded symbols for /var/vcap/packages/postgres/lib/libpq.so.5
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Loaded symbols for /lib/x86_64-linux-gnu/libpthread.so.0
Reading symbols from /lib/x86_64-linux-gnu/libcrypt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libcrypt.so.1
Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libm.so.6
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
0x00007f933063b8b3 in select () from /lib/x86_64-linux-gnu/libc.so.6
(gdb)
gdb-logs.txt (2,069 bytes)

t-ishii

2018-01-23 16:35

developer   ~0001908

Thanks but none of these are useful to me. Since it seems it is hard for you to take a stack trace on a core file, I will show another method to get stack trace when a segfault occurs.

1. Connect to pgpool using psql.
2. Look into the log file to find out the child pgpool process pid. In the log file "2018-01-23 07:12:34 Postico 1.3.1 CHILD[5140]...", 5140 is the process id you want.
3. Attach gdb. Run gdb from another terminal.
gdb path-to-pgpool 5140 (of course you need to replace "5140" with actual process id)
4. run "cont" command in gdb prompt.
5. Issue the query in question from psql.
6. gdb should react with the segafault and show a prompt. Type "bt" from the prompt and share with us.

jhiemer

2018-01-23 16:58

reporter   ~0001909

Hi t-ishii,
thanks a lot for your quick reply. The command issued was a simple: "\dt"

postgres/8c52e1ba-127c-4282-bb2d-033b8cfbc628:/var/vcap/packages/postgres/bin# ./psql -h 10.244.0.3 -U admin
Password for user admin:
psql (9.5.10)
Type "help" for help.

admin=# \dt

I attached the segmentation fault.

Thanks for your support!

segmentation-fault.txt (485,055 bytes)

t-ishii

2018-01-23 18:17

developer   ~0001910

Thanks. I will look into this.

t-ishii

2018-01-23 22:56

developer   ~0001911

It turned out if log_line_prefix includes %a and debug mode is on, an infinite recursion occurs, which eventually causes segfault.
Attached patch should fix the problem.

elog.diff (1,143 bytes)
diff --git a/src/utils/error/elog.c b/src/utils/error/elog.c
index cb3b403..1140836 100644
--- a/src/utils/error/elog.c
+++ b/src/utils/error/elog.c
@@ -43,7 +43,7 @@
  * overflow.)
  *
  *
- * Portions Copyright (c) 2003-2015, PgPool Global Development Group
+ * Portions Copyright (c) 2003-2018, PgPool Global Development Group
  * Portions Copyright (c) 1996-2015, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
@@ -1997,7 +1997,13 @@ log_line_prefix(StringInfo buf, const char *line_prefix, ErrorData *edata)
 		{
 			case 'a':	/* application name */
 			{
-				StartupPacket *sp = session? MASTER_CONNECTION(session->backend)->sp : NULL ;
+
+				/*
+				 * Do not use MASTER_CONNECTION macro here since it calls
+				 * pool_virtual_master_db_node_id() which eventually calls
+				 * ereport() if operated in DEBUG mode.
+				 */
+				StartupPacket *sp = session? (session->backend->slots[REAL_MASTER_NODE_ID])->sp : NULL ;
 				const char *appname = sp? sp->application_name : "[No Connection]";
 				if (appname == NULL || *appname == '\0')
 					appname = "[unknown]";
elog.diff (1,143 bytes)

jhiemer

2018-01-23 23:06

reporter   ~0001912

Hi t-ishii,
thanks we are going to try it out.

jhiemer

2018-01-23 23:13

reporter   ~0001913

Fixes the error. Are you going to put it into 3.6.9 and 3.7.2?

t-ishii

2018-01-24 06:12

developer   ~0001914

Thanks for testing it out. Yes, we are going to put it into them (plus 3.5 and 3.4 series).

Issue History

Date Modified Username Field Change
2018-01-12 17:48 yremmet New Issue
2018-01-12 17:48 yremmet File Added: pgpool.conf
2018-01-15 16:43 yremmet Note Added: 0001892
2018-01-15 16:51 yremmet Note Added: 0001893
2018-01-16 15:59 t-ishii Note Added: 0001895
2018-01-16 21:27 yremmet Note Added: 0001896
2018-01-17 10:18 t-ishii Note Added: 0001899
2018-01-18 01:11 yremmet File Added: ctl
2018-01-18 01:11 yremmet Note Added: 0001900
2018-01-18 07:46 t-ishii Note Added: 0001901
2018-01-18 07:47 t-ishii Status new => feedback
2018-01-19 09:58 t-ishii Assigned To => t-ishii
2018-01-19 09:58 t-ishii Status feedback => assigned
2018-01-23 16:20 jhiemer File Added: gdb-logs.txt
2018-01-23 16:20 jhiemer File Added: plain-connect-no-gdb-attached.txt
2018-01-23 16:20 jhiemer File Added: plain-connection-gdb-attached.txt
2018-01-23 16:20 jhiemer Note Added: 0001907
2018-01-23 16:35 t-ishii Note Added: 0001908
2018-01-23 16:36 t-ishii Status assigned => feedback
2018-01-23 16:58 jhiemer File Added: segmentation-fault.txt
2018-01-23 16:58 jhiemer Note Added: 0001909
2018-01-23 18:17 t-ishii Note Added: 0001910
2018-01-23 18:17 t-ishii Status feedback => assigned
2018-01-23 22:56 t-ishii File Added: elog.diff
2018-01-23 22:56 t-ishii Note Added: 0001911
2018-01-23 22:57 t-ishii Status assigned => feedback
2018-01-23 22:57 t-ishii Target Version => 3.7.2
2018-01-23 23:06 jhiemer Note Added: 0001912
2018-01-23 23:13 jhiemer Note Added: 0001913
2018-01-24 06:12 t-ishii Note Added: 0001914
2018-01-24 08:36 t-ishii Status feedback => resolved