Skip to content
This repository has been archived by the owner on Jul 3, 2023. It is now read-only.

Cannot query PrestoDB 0.107 #42

Open
fredrick opened this issue Oct 28, 2015 · 8 comments
Open

Cannot query PrestoDB 0.107 #42

fredrick opened this issue Oct 28, 2015 · 8 comments

Comments

@fredrick
Copy link

I am unable to query a Presto 0.107 cluster. For testing, I am attempting to query Presto's JMX data source.

Prestogres (master), ca0fa82
PostgreSQL 9.4
Presto 0.107

I can see that the following query in Presto works:

select table_schema, table_name, column_name, is_nullable, data_type from information_schema.columns

However:

psql -h 127.0.0.1 -p 5439 -U presto jmx   
psql (9.4.5)
Type "help" for help.

jmx=> SELECT * FROM sys.node;
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.

Prestogres logs:

LOG:  statement: select 1 from (select prestogres_catalog.setup_system_catalog(E'presto:8080', E'presto', E'jmx', E'jmx', E'presto')) s;
WARNING:  Table jmx."com.facebook.presto.execution:type=queryqueue,name=global,expansion=global" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."com.facebook.presto.execution:type=queryqueue,name=global,expansion=global" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=abstractconnector$acceptor,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletholder,name=org.eclipse.jetty.servlet.servlethandler$default404servlet-62d1dc3c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconnectionfactory,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconnectionfactory,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconnectionfactory,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.timingfilter-4a901445,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.util.thread:context=http/1.1@63d5874f,type=scheduledexecutorscheduler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.util.thread:context=http/1.1@63d5874f,type=scheduledexecutorscheduler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.util.thread:context=http/1.1@63d5874f,type=scheduledexecutorscheduler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletmapping,name=org.glassfish.jersey.servlet.servletcontainer-6e3ecf5c,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector$serverconnectormanager,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector$serverconnectormanager,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector$serverconnectormanager,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.io:context=http/1.1@63d5874f,type=arraybytebufferpool,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."sun.nio.ch:context=http/1.1@63d5874f,type=serversocketchannelimpl,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=httpconfiguration,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.server:context=http/1.1@63d5874f,type=serverconnector,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filtermapping,name=io.airlift.http.server.tracetokenfilter-6dc9da2d,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servlethandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=filterholder,name=org.eclipse.jetty.servlets.gzipfilter-6fbc1bb,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."org.eclipse.jetty.servlet:context=""root@@http"",type=servletcontexthandler,id=0" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."com.facebook.presto.failuredetector:name=heartbeatfailuredetector" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."com.facebook.presto.failuredetector:name=heartbeatfailuredetector" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."com.facebook.presto.failuredetector:name=heartbeatfailuredetector" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
WARNING:  Table jmx."com.facebook.presto.failuredetector:name=heartbeatfailuredetector" is skipped because its name is longer than 63 characters
CONTEXT:  PL/Python function "setup_system_catalog"
LOG:  statement: SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'pg_namespace'
LOG:  statement: SELECT count(*) from (SELECT has_function_privilege('presto', 'to_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE p.proname = 'to_regclass')) AS s
LOG:  statement: SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.oid = to_regclass('columns') AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'
LOG:  statement: create database "jmx"
ERROR:  database "jmx" already exists
STATEMENT:  create database "jmx"
LOG:  statement: create role "presto" with login
ERROR:  role "presto" already exists
STATEMENT:  create role "presto" with login
LOG:  statement: select prestogres_init_database('presto', 'jmx', E'host=\'127.0.0.1\' port=5432 dbname=\'jmx\' user=\'prestogres\' password=\'\'')
2015-10-27 15:23:10: pid 24: WARNING:  child process with pid: 44 was terminated by segmentation fault
LOG:  statement: do $INIT$ begin
            perform pg_advisory_lock(3235398540741723243);  -- prevent "tuple concurrently updated" error

            if not exists (select * from pg_language where lanname = 'plpythonu') then
                create language plpythonu;
            end if;

            if not exists (select * from pg_namespace where nspname = 'prestogres_catalog') then
                create schema prestogres_catalog;
            end if;

            create or replace function prestogres_catalog.start_presto_query(
                presto_server text, presto_user text, presto_catalog text, presto_schema text,
                function_name text, query text)
            returns void as $$
                import prestogres
                prestogres.start_presto_query(
                    presto_server, presto_user, presto_catalog, presto_schema, function_name, query)
            $$ language plpythonu
            security definer;

            create or replace function prestogres_catalog.setup_system_catalog(
                presto_server text, presto_user text, presto_catalog text, presto_schema text,
                access_role text)
            returns void as $$
                import prestogres
                prestogres.setup_system_catalog(
                    presto_server, presto_user, presto_catalog, presto_schema, access_role)
            $$ language plpythonu
            security definer;

            revoke temporary on database "jmx" from public;  -- reject CREATE TEMPORARY TABLE
            grant usage on schema prestogres_catalog to "presto";
            grant execute on all functions in schema prestogres_catalog to "presto";

        end $INIT$ language plpgsql
2015-10-27 15:30:15: pid 164: LOG:  Frontend terminated
@frsyuki
Copy link
Member

frsyuki commented Oct 29, 2015

The error message says:

LOG:  statement: select prestogres_init_database('presto', 'jmx', E'host=\'127.0.0.1\' port=5432 dbname=\'jmx\' user=\'prestogres\' password=\'\'')
2015-10-27 15:23:10: pid 24: WARNING:  child process with pid: 44 was terminated by segmentation fault

So, child process crashed. Do you have logs of pgpool2?

@fredrick
Copy link
Author

@frsyuki Where are these logs located? Running prestogres-ctl pgpool just from an interactive terminal.

@fredrick
Copy link
Author

I manually started prestogres-pgpool in debug mode. Logs for same query below:

/usr/local/bin/prestogres-pgpool -n -d
2015-10-27 16:27:10: pid 237: DEBUG:  loading hba configuration
2015-10-27 16:27:10: pid 237: DETAIL:  loading file :"/usr/local/etc/prestogres_hba.conf" for client authentication configuration file
2015-10-27 16:27:10: pid 237: LOG:  Setting up socket for 0.0.0.0:5439
2015-10-27 16:27:10: pid 238: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 239: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 237: LOG:  prestogres successfully started. version 0.6.7 (tataraboshi)
2015-10-27 16:27:10: pid 237: DEBUG:  find_primary_node: not in streaming replication mode
2015-10-27 16:27:10: pid 262: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 240: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 261: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 254: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 257: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 263: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 238: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 260: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 239: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 264: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 242: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 241: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 265: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 266: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 243: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 259: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 244: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 254: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 267: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 245: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 268: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 246: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 269: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 247: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 258: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 248: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 239: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 239: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 239: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 256: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 270: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 249: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 271: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 272: DEBUG:  I am PCP child with pid:272
2015-10-27 16:27:10: pid 252: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 273: DEBUG:  I am 273
2015-10-27 16:27:10: pid 250: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 253: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 273: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 272: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 272: DEBUG:  initializing backend status
2015-10-27 16:27:10: pid 254: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 254: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 254: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 241: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 262: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 261: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 238: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 238: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 238: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 240: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 264: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 244: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 263: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 242: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 265: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 260: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 268: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 267: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 266: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 245: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 259: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 243: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 246: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 257: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 256: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 247: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 249: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 271: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 250: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 253: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 270: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 241: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 241: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 241: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 261: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 261: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 261: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 258: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 252: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 262: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 240: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 240: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 240: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 262: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 262: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 269: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 248: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:10: pid 263: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 263: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 263: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 264: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 264: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 264: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 249: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 249: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 249: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 244: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 244: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 244: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 265: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 265: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 265: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 242: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 242: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 242: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 260: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 260: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 260: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 267: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 267: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 267: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 266: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 266: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 266: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 243: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 243: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 243: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 245: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 245: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 245: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 257: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 257: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 257: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 256: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 256: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 256: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 259: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 259: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 259: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 246: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 246: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 246: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 248: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 248: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 248: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 270: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 270: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 270: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 271: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 271: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 271: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 250: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 250: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 250: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 247: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 247: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 247: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 269: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 253: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 253: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 253: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 269: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 269: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 258: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 258: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 258: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 252: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 252: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 252: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:10: pid 268: DEBUG:  authenticate kind = 0
2015-10-27 16:27:10: pid 268: DEBUG:  authenticate backend: key data received
2015-10-27 16:27:10: pid 268: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:27:30: pid 252: DEBUG:  I am 252 accept fd 9
2015-10-27 16:27:30: pid 252: DEBUG:  reading startup packet
2015-10-27 16:27:30: pid 252: DETAIL:  Protocol Major: 1234 Minor: 5679 database:  user: 
2015-10-27 16:27:30: pid 252: DEBUG:  selecting backend connection
2015-10-27 16:27:30: pid 252: DETAIL:  SSLRequest from client
2015-10-27 16:27:30: pid 252: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:30: pid 252: DEBUG:  reading startup packet
2015-10-27 16:27:30: pid 252: DETAIL:  application_name: psql
2015-10-27 16:27:30: pid 252: DEBUG:  reading startup packet
2015-10-27 16:27:30: pid 252: DETAIL:  Protocol Major: 3 Minor: 0 database: jmx user: presto
2015-10-27 16:27:30: pid 252: DEBUG:  prestogres_init_hba: presto_server: presto:8080
2015-10-27 16:27:30: pid 252: DEBUG:  prestogres_init_hba: presto_user: presto
2015-10-27 16:27:30: pid 252: DEBUG:  prestogres_init_hba: presto_catalog: jmx
2015-10-27 16:27:30: pid 252: DEBUG:  prestogres_init_hba: presto_schema: jmx
2015-10-27 16:27:30: pid 252: DEBUG:  creating new connection to backend
2015-10-27 16:27:30: pid 252: DETAIL:  connecting 0 backend
2015-10-27 16:27:30: pid 252: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  slot: 0 length: 8
2015-10-27 16:27:30: pid 252: DEBUG:  authentication backend
2015-10-27 16:27:30: pid 252: DETAIL:  auth kind:0
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 26
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"application_name" value:"psql"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 25
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"client_encoding" value:"UTF8"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 23
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"DateStyle" value:"ISO, MDY"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 25
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"integer_datetimes" value:"on"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 27
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"IntervalStyle" value:"postgres"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 21
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"is_superuser" value:"off"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 25
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"server_encoding" value:"UTF8"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 25
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"server_version" value:"9.4.5"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 33
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"session_authorization" value:"presto"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 35
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"standard_conforming_strings" value:"on"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  master slot: 0 length: 17
2015-10-27 16:27:30: pid 252: DEBUG:  process parameter status
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 name:"TimeZone" value:"UTC"
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  slot: 0 length: 12
2015-10-27 16:27:30: pid 252: DEBUG:  authentication backend
2015-10-27 16:27:30: pid 252: DETAIL:  cp->info[i]:0x7f5cb9018400 pid:338
2015-10-27 16:27:30: pid 252: DEBUG:  sending backend key data
2015-10-27 16:27:30: pid 252: DETAIL:  send pid 338 to frontend
2015-10-27 16:27:30: pid 252: DEBUG:  selecting load balance node
2015-10-27 16:27:30: pid 252: DETAIL:  selected backend id is 0
2015-10-27 16:27:30: pid 252: DEBUG:  initializing session context
2015-10-27 16:27:30: pid 252: DETAIL:  selected load balancing node: 0
2015-10-27 16:27:30: pid 252: DEBUG:  session context: clearing transaction isolation. DONE
2015-10-27 16:27:30: pid 252: DEBUG:  session context: clearing writing transaction. DONE
2015-10-27 16:27:30: pid 252: DEBUG:  session context: clearing failed transaction. DONE
2015-10-27 16:27:30: pid 252: DEBUG:  session context: clearing failed transaction. DONE
2015-10-27 16:27:30: pid 252: DEBUG:  session context: clearing skip reading from backends. DONE
2015-10-27 16:27:30: pid 252: DEBUG:  session context: clearing ignore till sync. DONE
2015-10-27 16:27:30: pid 252: DEBUG:  reading backend data packet kind
2015-10-27 16:27:30: pid 252: DETAIL:  backend:0 of 1 kind = 'Z'
2015-10-27 16:27:30: pid 252: DEBUG:  processing backend response
2015-10-27 16:27:30: pid 252: DETAIL:  received kind 'Z'(5a) from backend
2015-10-27 16:27:30: pid 252: DEBUG:  processing backend response
2015-10-27 16:27:30: pid 252: DETAIL:  Ready For Query received
2015-10-27 16:27:30: pid 252: DEBUG:  reading message length
2015-10-27 16:27:30: pid 252: DETAIL:  slot: 0 length: 5
2015-10-27 16:27:30: pid 252: DEBUG:  processing ReadyForQuery
2015-10-27 16:27:30: pid 252: DETAIL:  transaction state '
2015-10-27 16:28:11: pid 252: DEBUG:  processing frontend response
2015-10-27 16:28:11: pid 252: DETAIL:  received kind 'Q'(51) from frontend
2015-10-27 16:28:11: pid 252: DEBUG:  session context: clearing doing extended query messaging. DONE
2015-10-27 16:28:11: pid 252: LOG:  statement: SELECT * FROM sys.node;
2015-10-27 16:28:11: pid 252: DEBUG:  session context: setting query in progress. DONE
2015-10-27 16:28:11: pid 252: DEBUG:  do_query: extended:0 query:"select 1 from (select prestogres_catalog.setup_system_catalog(E'presto:8080', E'presto', E'jmx', E'jmx', E'presto')) s;"
2015-10-27 16:28:11: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'T'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received ROW DESCRIPTION ('T')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: row description: num_fileds: 1
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'N'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'D'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received DATA ROW ('D')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'C'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received COMMAND COMPLETE ('C')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'Z'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received READY FOR QUERY ('Z')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  system catalog walker, checking relation "node"
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: extended:0 query:"SELECT count(*) FROM pg_catalog.pg_class AS c WHERE c.relname = 'pg_namespace'"
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'T'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received ROW DESCRIPTION ('T')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: row description: num_fileds: 1
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'D'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received DATA ROW ('D')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'C'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received COMMAND COMPLETE ('C')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'Z'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received READY FOR QUERY ('Z')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: extended:0 query:"SELECT count(*) from (SELECT has_function_privilege('presto', 'to_regclass(cstring)', 'execute') WHERE EXISTS(SELECT * FROM pg_catalog.pg_proc AS p WHERE p.proname = 'to_regclass')) AS s"
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'T'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received ROW DESCRIPTION ('T')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: row description: num_fileds: 1
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'D'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received DATA ROW ('D')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'C'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received COMMAND COMPLETE ('C')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'Z'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received READY FOR QUERY ('Z')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: extended:0 query:"SELECT count(*) FROM pg_class AS c, pg_namespace AS n WHERE c.oid = to_regclass('node') AND c.relnamespace = n.oid AND n.nspname = 'pg_catalog'"
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'T'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received ROW DESCRIPTION ('T')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: row description: num_fileds: 1
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'D'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received DATA ROW ('D')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'C'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received COMMAND COMPLETE ('C')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: kind: 'Z'
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: received READY FOR QUERY ('Z')
2015-10-27 16:28:12: pid 252: CONTEXT:  while searching system catalog, When relcache is missed
2015-10-27 16:28:12: pid 252: DEBUG:  prestogres_send_to_where: select, insert, create table
2015-10-27 16:28:12: pid 252: DEBUG:  run_and_rewrite_presto_query: partial_rewrite_index -1, has_cursor 0
2015-10-27 16:28:12: pid 252: DEBUG:  run_and_rewrite_presto_query: adding 'limit 1000' to a SELECT * query
2015-10-27 16:28:12: pid 252: DEBUG:  do_query: extended:0 query:"select prestogres_catalog.start_presto_query(E'presto:8080', E'presto', E'jmx', E'jmx', E'presto_fetch', E'SELECT * FROM sys.node limit 1000')"
2015-10-27 16:28:12: pid 237: DEBUG:  reaper handler
2015-10-27 16:28:12: pid 237: WARNING:  child process with pid: 252 was terminated by segmentation fault
2015-10-27 16:28:12: pid 237: DEBUG:  reaper handler: child with PID:252 exits with status 11 by signal 11
2015-10-27 16:28:12: pid 237: DEBUG:  reaper handler: forked a new child with PID:341
2015-10-27 16:28:12: pid 237: DEBUG:  reaper handler: exiting normally
2015-10-27 16:28:12: pid 341: DEBUG:  initializing backend status
2015-10-27 16:28:12: pid 268: DEBUG:  I am 268 accept fd 9
2015-10-27 16:28:12: pid 268: DEBUG:  reading startup packet
2015-10-27 16:28:12: pid 268: DETAIL:  application_name: psql
2015-10-27 16:28:12: pid 268: DEBUG:  reading startup packet
2015-10-27 16:28:12: pid 268: DETAIL:  Protocol Major: 3 Minor: 0 database: jmx user: presto
2015-10-27 16:28:12: pid 268: DEBUG:  prestogres_init_hba: presto_server: presto:8080
2015-10-27 16:28:12: pid 268: DEBUG:  prestogres_init_hba: presto_user: presto
2015-10-27 16:28:12: pid 268: DEBUG:  prestogres_init_hba: presto_catalog: jmx
2015-10-27 16:28:12: pid 268: DEBUG:  prestogres_init_hba: presto_schema: jmx
2015-10-27 16:28:12: pid 341: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:28:12: pid 341: DEBUG:  authenticate kind = 0
2015-10-27 16:28:12: pid 341: DEBUG:  authenticate backend: key data received
2015-10-27 16:28:12: pid 341: DEBUG:  authenticate backend: transaction state: I
2015-10-27 16:28:12: pid 268: DEBUG:  creating new connection to backend
2015-10-27 16:28:12: pid 268: DETAIL:  connecting 0 backend
2015-10-27 16:28:12: pid 268: DEBUG:  SSL is requested but SSL support is not available
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  slot: 0 length: 8
2015-10-27 16:28:12: pid 268: DEBUG:  authentication backend
2015-10-27 16:28:12: pid 268: DETAIL:  auth kind:0
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 26
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"application_name" value:"psql"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 25
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"client_encoding" value:"UTF8"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 23
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"DateStyle" value:"ISO, MDY"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 25
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"integer_datetimes" value:"on"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 27
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"IntervalStyle" value:"postgres"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 21
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"is_superuser" value:"off"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 25
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"server_encoding" value:"UTF8"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 25
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"server_version" value:"9.4.5"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 33
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"session_authorization" value:"presto"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 35
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"standard_conforming_strings" value:"on"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  master slot: 0 length: 17
2015-10-27 16:28:12: pid 268: DEBUG:  process parameter status
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 name:"TimeZone" value:"UTC"
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  slot: 0 length: 12
2015-10-27 16:28:12: pid 268: DEBUG:  authentication backend
2015-10-27 16:28:12: pid 268: DETAIL:  cp->info[i]:0x7f5cb9058000 pid:345
2015-10-27 16:28:12: pid 268: DEBUG:  sending backend key data
2015-10-27 16:28:12: pid 268: DETAIL:  send pid 345 to frontend
2015-10-27 16:28:12: pid 268: DEBUG:  selecting load balance node
2015-10-27 16:28:12: pid 268: DETAIL:  selected backend id is 0
2015-10-27 16:28:12: pid 268: DEBUG:  initializing session context
2015-10-27 16:28:12: pid 268: DETAIL:  selected load balancing node: 0
2015-10-27 16:28:12: pid 268: DEBUG:  session context: clearing transaction isolation. DONE
2015-10-27 16:28:12: pid 268: DEBUG:  session context: clearing writing transaction. DONE
2015-10-27 16:28:12: pid 268: DEBUG:  session context: clearing failed transaction. DONE
2015-10-27 16:28:12: pid 268: DEBUG:  session context: clearing failed transaction. DONE
2015-10-27 16:28:12: pid 268: DEBUG:  session context: clearing skip reading from backends. DONE
2015-10-27 16:28:12: pid 268: DEBUG:  session context: clearing ignore till sync. DONE
2015-10-27 16:28:12: pid 268: DEBUG:  reading backend data packet kind
2015-10-27 16:28:12: pid 268: DETAIL:  backend:0 of 1 kind = 'Z'
2015-10-27 16:28:12: pid 268: DEBUG:  processing backend response
2015-10-27 16:28:12: pid 268: DETAIL:  received kind 'Z'(5a) from backend
2015-10-27 16:28:12: pid 268: DEBUG:  processing backend response
2015-10-27 16:28:12: pid 268: DETAIL:  Ready For Query received
2015-10-27 16:28:12: pid 268: DEBUG:  reading message length
2015-10-27 16:28:12: pid 268: DETAIL:  slot: 0 length: 5
2015-10-27 16:28:12: pid 268: DEBUG:  processing ReadyForQuery
2015-10-27 16:28:12: pid 268: DETAIL:  transaction state '

@fredrick
Copy link
Author

@frsyuki I have better information! [EDIT, include --track-origins=yes]

Below is the trace output from valgrind:

valgrind --track-origins=yes /usr/local/bin/prestogres-pgpool -n
==473== Memcheck, a memory error detector
==473== Copyright (C) 2002-2013, and GNU GPL'd, by Julian Seward et al.
==473== Using Valgrind-3.10.0 and LibVEX; rerun with -h for copyright info
==473== Command: /usr/local/bin/prestogres-pgpool -n
==473== 
2015-10-27 18:50:20: pid 473: LOG:  Setting up socket for 0.0.0.0:5439
2015-10-27 18:50:24: pid 473: LOG:  prestogres successfully started. version 0.6.7 (tataraboshi)
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x4C2C1A9: strlen (vg_replace_strmem.c:412)
==484==    by 0x468C31: MemoryContextStrdup (mcxt.c:832)
==484==    by 0x42383D: read_startup_packet (child.c:625)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x423882: read_startup_packet (child.c:635)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x423884: read_startup_packet (child.c:635)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x423893: read_startup_packet (child.c:635)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x423895: read_startup_packet (child.c:635)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x4238A4: read_startup_packet (child.c:636)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x4238A6: read_startup_packet (child.c:636)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x4238B5: read_startup_packet (child.c:637)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
==484== Conditional jump or move depends on uninitialised value(s)
==484==    at 0x4238B7: read_startup_packet (child.c:637)
==484==    by 0x426137: get_backend_connection (child.c:2231)
==484==    by 0x426137: do_child (child.c:365)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Uninitialised value was created by a heap allocation
==484==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==484==    by 0x469277: AllocSetAlloc (aset.c:867)
==484==    by 0x46680B: pool_open (pool_stream.c:81)
==484==    by 0x4260C8: get_connection (child.c:2207)
==484==    by 0x4260C8: do_child (child.c:350)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484== 
2015-10-27 18:50:52: pid 484: LOG:  statement: SELECT * FROM sys.node;
==484== Invalid read of size 4
==484==    at 0x46730F: pool_write_noerror (pool_stream.c:385)
==484==    by 0x46730F: pool_write (pool_stream.c:428)
==484==    by 0x4278D3: send_simplequery_message (pool_process_query.c:755)
==484==    by 0x42C5B2: do_query_or_get_error_message (pool_process_query.c:2435)
==484==    by 0x44146F: run_and_rewrite_presto_query (pool_query_context.c:2162)
==484==    by 0x43227A: SimpleQuery (pool_proto_modules.c:383)
==484==    by 0x434FD3: ProcessFrontendResponse (pool_proto_modules.c:2388)
==484==    by 0x42B381: read_packets_and_process.constprop.11 (pool_process_query.c:4803)
==484==    by 0x42BB0A: pool_process_query (pool_process_query.c:263)
==484==    by 0x4263A1: do_child (child.c:407)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  Address 0x498 is not stack'd, malloc'd or (recently) free'd
==484== 
==484== 
==484== Process terminating with default action of signal 11 (SIGSEGV)
==484==  Access not within mapped region at address 0x498
==484==    at 0x46730F: pool_write_noerror (pool_stream.c:385)
==484==    by 0x46730F: pool_write (pool_stream.c:428)
==484==    by 0x4278D3: send_simplequery_message (pool_process_query.c:755)
==484==    by 0x42C5B2: do_query_or_get_error_message (pool_process_query.c:2435)
==484==    by 0x44146F: run_and_rewrite_presto_query (pool_query_context.c:2162)
==484==    by 0x43227A: SimpleQuery (pool_proto_modules.c:383)
==484==    by 0x434FD3: ProcessFrontendResponse (pool_proto_modules.c:2388)
==484==    by 0x42B381: read_packets_and_process.constprop.11 (pool_process_query.c:4803)
==484==    by 0x42BB0A: pool_process_query (pool_process_query.c:263)
==484==    by 0x4263A1: do_child (child.c:407)
==484==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==484==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==484==    by 0x404FEE: main (main.c:319)
==484==  If you believe this happened as a result of a stack
==484==  overflow in your program's main thread (unlikely but
==484==  possible), you can try to increase the size of the
==484==  main thread stack using the --main-stacksize= flag.
==484==  The main thread stack size used in this run was 8388608.
==484== 
==484== HEAP SUMMARY:
==484==     in use at exit: 2,532,333 bytes in 1,074 blocks
==484==   total heap usage: 1,862 allocs, 788 frees, 2,594,392 bytes allocated
==484== 
==484== LEAK SUMMARY:
==484==    definitely lost: 120 bytes in 1 blocks
==484==    indirectly lost: 447 bytes in 14 blocks
==484==      possibly lost: 0 bytes in 0 blocks
==484==    still reachable: 2,531,766 bytes in 1,059 blocks
==484==         suppressed: 0 bytes in 0 blocks
==484== Rerun with --leak-check=full to see details of leaked memory
==484== 
==484== For counts of detected and suppressed errors, rerun with: -v
==484== ERROR SUMMARY: 10 errors from 10 contexts (suppressed: 0 from 0)
2015-10-27 18:50:54: pid 473: WARNING:  child process with pid: 484 was terminated by segmentation fault

@frsyuki
Copy link
Member

frsyuki commented Oct 29, 2015

Good information.
Invalid read of size 4 looks problematic, which is suggesting that a POOL_CONNECTION_POOL object created by CONNECTION(backend, session_context->load_balance_node_id); call at pool_query_context.c:2093 is broken. But that warning is from parent process. The process crashed is a child process.
So, could you run valgrind with --trace-children=yes option?
A weird thing is that I doesn't reproduce on my machine (linux 3.2.0, gcc 4.6.3, postgresql 9.3.9).

@fredrick
Copy link
Author

System information:

uname -a
Linux 802e06968f7d 3.19.0-25-generic #26~14.04.1-Ubuntu SMP Fri Jul 24 21:16:20 UTC 2015 x86_64 GNU/Linux

SELECT version();
PostgreSQL 9.3.10 on x86_64-unknown-linux-gnu, compiled by gcc (Debian 4.9.2-10) 4.9.2, 64-bit
(1 row)

Here is the output of valgrind --track-origins=yes --trace-children=yes -v /usr/local/bin/prestogres-pgpool -n after SELECT * FROM sys.node;

2015-10-28 07:40:44: pid 2421: LOG:  statement: SELECT * FROM sys.node;
--2421-- REDIR: 0x5f79300 (libc.so.6:__strcasecmp_avx) redirected to 0x4c2caa0 (strcasecmp)
==2421== Invalid read of size 4
==2421==    at 0x46730F: pool_write_noerror (pool_stream.c:385)
==2421==    by 0x46730F: pool_write (pool_stream.c:428)
==2421==    by 0x4278D3: send_simplequery_message (pool_process_query.c:755)
==2421==    by 0x42C5B2: do_query_or_get_error_message (pool_process_query.c:2435)
==2421==    by 0x44146F: run_and_rewrite_presto_query (pool_query_context.c:2162)
==2421==    by 0x43227A: SimpleQuery (pool_proto_modules.c:383)
==2421==    by 0x434FD3: ProcessFrontendResponse (pool_proto_modules.c:2388)
==2421==    by 0x42B381: read_packets_and_process.constprop.11 (pool_process_query.c:4803)
==2421==    by 0x42BB0A: pool_process_query (pool_process_query.c:263)
==2421==    by 0x4263A1: do_child (child.c:407)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Address 0x498 is not stack'd, malloc'd or (recently) free'd
==2421== 
==2421== 
==2421== Process terminating with default action of signal 11 (SIGSEGV)
==2421==  Access not within mapped region at address 0x498
==2421==    at 0x46730F: pool_write_noerror (pool_stream.c:385)
==2421==    by 0x46730F: pool_write (pool_stream.c:428)
==2421==    by 0x4278D3: send_simplequery_message (pool_process_query.c:755)
==2421==    by 0x42C5B2: do_query_or_get_error_message (pool_process_query.c:2435)
==2421==    by 0x44146F: run_and_rewrite_presto_query (pool_query_context.c:2162)
==2421==    by 0x43227A: SimpleQuery (pool_proto_modules.c:383)
==2421==    by 0x434FD3: ProcessFrontendResponse (pool_proto_modules.c:2388)
==2421==    by 0x42B381: read_packets_and_process.constprop.11 (pool_process_query.c:4803)
==2421==    by 0x42BB0A: pool_process_query (pool_process_query.c:263)
==2421==    by 0x4263A1: do_child (child.c:407)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  If you believe this happened as a result of a stack
==2421==  overflow in your program's main thread (unlikely but
==2421==  possible), you can try to increase the size of the
==2421==  main thread stack using the --main-stacksize= flag.
==2421==  The main thread stack size used in this run was 8388608.
--2421-- Discarding syms at 0x94c03b0-0x94c4b4e in /lib/x86_64-linux-gnu/libnss_compat-2.19.so due to munmap()
--2421-- Discarding syms at 0x96c91a0-0x96cf1bc in /lib/x86_64-linux-gnu/libnss_nis-2.19.so due to munmap()
--2421-- Discarding syms at 0x98d42a0-0x98da803 in /lib/x86_64-linux-gnu/libnss_files-2.19.so due to munmap()
==2421== 
==2421== HEAP SUMMARY:
==2421==     in use at exit: 2,532,333 bytes in 1,074 blocks
==2421==   total heap usage: 1,862 allocs, 788 frees, 2,594,392 bytes allocated
==2421== 
==2421== Searching for pointers to 1,074 not-freed blocks
==2421== Checked 5,356,312 bytes
==2421== 
==2421== LEAK SUMMARY:
==2421==    definitely lost: 120 bytes in 1 blocks
==2421==    indirectly lost: 447 bytes in 14 blocks
==2421==      possibly lost: 0 bytes in 0 blocks
==2421==    still reachable: 2,531,766 bytes in 1,059 blocks
==2421==         suppressed: 0 bytes in 0 blocks
==2421== Rerun with --leak-check=full to see details of leaked memory
==2421== 
==2421== ERROR SUMMARY: 10 errors from 10 contexts (suppressed: 0 from 0)
==2421== 
==2421== 1 errors in context 1 of 10:
==2421== Invalid read of size 4
==2421==    at 0x46730F: pool_write_noerror (pool_stream.c:385)
==2421==    by 0x46730F: pool_write (pool_stream.c:428)
==2421==    by 0x4278D3: send_simplequery_message (pool_process_query.c:755)
==2421==    by 0x42C5B2: do_query_or_get_error_message (pool_process_query.c:2435)
==2421==    by 0x44146F: run_and_rewrite_presto_query (pool_query_context.c:2162)
==2421==    by 0x43227A: SimpleQuery (pool_proto_modules.c:383)
==2421==    by 0x434FD3: ProcessFrontendResponse (pool_proto_modules.c:2388)
==2421==    by 0x42B381: read_packets_and_process.constprop.11 (pool_process_query.c:4803)
==2421==    by 0x42BB0A: pool_process_query (pool_process_query.c:263)
==2421==    by 0x4263A1: do_child (child.c:407)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Address 0x498 is not stack'd, malloc'd or (recently) free'd
==2421== 
==2421== 
==2421== 1 errors in context 2 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x4238B7: read_startup_packet (child.c:637)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 3 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x4238B5: read_startup_packet (child.c:637)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 4 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x4238A6: read_startup_packet (child.c:636)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 5 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x4238A4: read_startup_packet (child.c:636)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 6 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x423895: read_startup_packet (child.c:635)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 7 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x423893: read_startup_packet (child.c:635)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 8 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x423884: read_startup_packet (child.c:635)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 9 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x423882: read_startup_packet (child.c:635)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== 
==2421== 1 errors in context 10 of 10:
==2421== Conditional jump or move depends on uninitialised value(s)
==2421==    at 0x4C2C1A9: strlen (vg_replace_strmem.c:412)
==2421==    by 0x468C31: MemoryContextStrdup (mcxt.c:832)
==2421==    by 0x42383D: read_startup_packet (child.c:625)
==2421==    by 0x426137: get_backend_connection (child.c:2231)
==2421==    by 0x426137: do_child (child.c:365)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421==  Uninitialised value was created by a heap allocation
==2421==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==2421==    by 0x469277: AllocSetAlloc (aset.c:867)
==2421==    by 0x46680B: pool_open (pool_stream.c:81)
==2421==    by 0x4260C8: get_connection (child.c:2207)
==2421==    by 0x4260C8: do_child (child.c:350)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)
==2421== 
==2421== ERROR SUMMARY: 10 errors from 10 contexts (suppressed: 0 from 0)
2015-10-28 07:40:46: pid 2354: WARNING:  child process with pid: 2421 was terminated by segmentation fault
==2457== embedded gdbserver: reading from /tmp/vgdb-pipe-from-vgdb-to-2457-by-???-on-802e06968f7d
==2457== embedded gdbserver: writing to   /tmp/vgdb-pipe-to-vgdb-from-2457-by-???-on-802e06968f7d
==2457== embedded gdbserver: shared mem   /tmp/vgdb-pipe-shared-mem-vgdb-2457-by-???-on-802e06968f7d
==2457== 
==2457== TO CONTROL THIS PROCESS USING vgdb (which you probably
==2457== don't want to do, unless you know exactly what you're doing,
==2457== or are doing some strange experiment):
==2457==   /usr/lib/valgrind/../../bin/vgdb --pid=2457 ...command...
==2457== 
==2457== TO DEBUG THIS PROCESS USING GDB: start GDB like this
==2457==   /path/to/gdb /usr/local/bin/prestogres-pgpool
==2457== and then give GDB the following command
==2457==   target remote | /usr/lib/valgrind/../../bin/vgdb --pid=2457
==2457== --pid is optional if only one valgrind process is running
==2457== 
--2457-- REDIR: 0xffffffffff600000 (???:???) redirected to 0x380bd803 (vgPlain_amd64_linux_REDIR_FOR_vgettimeofday)
--2457-- REDIR: 0x5ed90d0 (libc.so.6:__GI_strncmp) redirected to 0x4c2c950 (__GI_strncmp)
--2457-- REDIR: 0x5edcca0 (libc.so.6:__GI_stpcpy) redirected to 0x4c2eeb0 (__GI_stpcpy)
--2457-- Reading syms from /lib/x86_64-linux-gnu/libnss_compat-2.19.so
--2457--   Considering /lib/x86_64-linux-gnu/libnss_compat-2.19.so ..
--2457--   .. CRC mismatch (computed cd218bc1 wanted 4035e739)
--2457--   Considering /usr/lib/debug/lib/x86_64-linux-gnu/libnss_compat-2.19.so ..
--2457--   .. CRC is valid
--2457-- Reading syms from /lib/x86_64-linux-gnu/libnss_nis-2.19.so
--2457--   Considering /lib/x86_64-linux-gnu/libnss_nis-2.19.so ..
--2457--   .. CRC mismatch (computed 19f9d1c9 wanted dd684ba2)
--2457--   Considering /usr/lib/debug/lib/x86_64-linux-gnu/libnss_nis-2.19.so ..
--2457--   .. CRC is valid
--2457-- Reading syms from /lib/x86_64-linux-gnu/libnss_files-2.19.so
--2457--   Considering /lib/x86_64-linux-gnu/libnss_files-2.19.so ..
--2457--   .. CRC mismatch (computed 2e8f5878 wanted 94f7ac29)
--2457--   Considering /usr/lib/debug/lib/x86_64-linux-gnu/libnss_files-2.19.so ..
--2457--   .. CRC is valid
--2457-- REDIR: 0x5ee3590 (libc.so.6:rawmemchr) redirected to 0x4c2fab0 (rawmemchr)

@frsyuki
Copy link
Member

frsyuki commented Oct 30, 2015

hmm...so, this is the cause:

==2421== Process terminating with default action of signal 11 (SIGSEGV)
==2421==  Access not within mapped region at address 0x498
==2421==    at 0x46730F: pool_write_noerror (pool_stream.c:385)
==2421==    by 0x46730F: pool_write (pool_stream.c:428)
==2421==    by 0x4278D3: send_simplequery_message (pool_process_query.c:755)
==2421==    by 0x42C5B2: do_query_or_get_error_message (pool_process_query.c:2435)
==2421==    by 0x44146F: run_and_rewrite_presto_query (pool_query_context.c:2162)
==2421==    by 0x43227A: SimpleQuery (pool_proto_modules.c:383)
==2421==    by 0x434FD3: ProcessFrontendResponse (pool_proto_modules.c:2388)
==2421==    by 0x42B381: read_packets_and_process.constprop.11 (pool_process_query.c:4803)
==2421==    by 0x42BB0A: pool_process_query (pool_process_query.c:263)
==2421==    by 0x4263A1: do_child (child.c:407)
==2421==    by 0x4072FB: fork_a_child (pgpool_main.c:672)
==2421==    by 0x40A607: PgpoolMain (pgpool_main.c:278)
==2421==    by 0x404FEE: main (main.c:319)

This means that connection is not configured appropriately. But hm...I don't know why it happens...
Could you review your prestogres.conf file? The latest template is here:
https://github.com/treasure-data/prestogres/blob/master/prestogres/config/prestogres.conf

@fredrick
Copy link
Author

There is only one change, which is to use a hostname presto instead of 127.0.0.1 for the presto_server. Full diff here: https://www.diffchecker.com/qrbdktdc

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@frsyuki @fredrick