treasure-data / prestogres

PostgreSQL protocol gateway for Presto distributed SQL query engine
Other
292 stars 61 forks source link

Cannot query PrestoDB 0.107 #42

Open fredrick opened 9 years ago

fredrick commented 9 years ago

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

Prestogres (master), ca0fa82be692582f728e34a4a96b8d01e373836f 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 commented 9 years ago

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 commented 9 years ago

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

fredrick commented 9 years ago

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 commented 9 years ago

@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 commented 9 years ago

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 commented 9 years ago

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 commented 9 years ago

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 commented 9 years ago

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