simple queries to mySQL server hang Presto

[avasil...@groupon.com]

Guys, please take a look. Any insights/debugging tips are greatly appreciated.

I'm running Presto 0.92 on the 2-node test cluster:

node 1: coordinator+discovery
node 2: worker

I'm using single mySQL connector and single schema to test several queries. Some queries work fine however some hang Presto with subsequent required worker & coordinator restart. The behavior is reproducible. Example of the query that gets stuck:

presto:default> SELECT type FROM mysql.service.item limit 10;

Query 20150205_183044_00014_xduyk, RUNNING, 1 node, 2 splits
0:16 [ 0 rows, 0B] [ 0 rows/s, 0B/s] [>>>>>>>>>>>>>>>>>>>>> ] 0%

STAGES ROWS ROWS/s BYTES BYTES/s QUEUED RUN DONE
0.........R 0 0 0B 0B 0 1 0
1.......R 0 0 0B 0B 1 0 0

Coordinator log:

2015-02-05T18:30:44.625+0000 DEBUG query-execution-37 com.facebook.presto.execution.QueryStateMachine Query 20150205_183044_00014_xduyk is PLANNING
2015-02-05T18:30:44.671+0000 DEBUG query-execution-37 com.facebook.presto.execution.QueryStateMachine Query 20150205_183044_00014_xduyk is STARTING
2015-02-05T18:30:44.678+0000 DEBUG query-execution-39 com.facebook.presto.execution.SqlStageExecution Stage 20150205_183044_00014_xduyk.0 is SCHEDULING
2015-02-05T18:30:44.679+0000 DEBUG query-execution-40 com.facebook.presto.execution.SqlStageExecution Stage 20150205_183044_00014_xduyk.1 is SCHEDULING
2015-02-05T18:30:44.682+0000 DEBUG query-execution-41 com.facebook.presto.execution.SqlStageExecution Stage 20150205_183044_00014_xduyk.1 is SCHEDULED
2015-02-05T18:30:44.699+0000 DEBUG query-execution-42 com.facebook.presto.execution.SqlStageExecution Stage 20150205_183044_00014_xduyk.0 is SCHEDULED
2015-02-05T18:30:44.702+0000 DEBUG query-execution-41 com.facebook.presto.execution.QueryStateMachine Query 20150205_183044_00014_xduyk is RUNNING
2015-02-05T18:30:44.704+0000 DEBUG query-execution-41 com.facebook.presto.execution.SqlStageExecution Stage 20150205_183044_00014_xduyk.1 is RUNNING
2015-02-05T18:30:44.710+0000 DEBUG query-execution-41 com.facebook.presto.execution.SqlStageExecution Stage 20150205_183044_00014_xduyk.0 is RUNNING
2015-02-05T18:33:37.580+0000 WARN ContinuousTaskInfoFetcher-20150205_183044_00014_xduyk.0.0-749 com.facebook.presto.server.HttpRemoteTask Error updating task 20150205_183044_00014_xduyk.0.0: Server returned SERVICE_UNAVAILABLE: http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.0.0?summarize: http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.0.0
2015-02-05T18:35:16.948+0000 WARN ContinuousTaskInfoFetcher-20150205_183044_00014_xduyk.1.0-754 com.facebook.presto.server.HttpRemoteTask Error updating task 20150205_183044_00014_xduyk.1.0: Server returned SERVICE_UNAVAILABLE: http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.1.0?summarize: http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.1.0
2015-02-05T18:35:16.948+0000 WARN ContinuousTaskInfoFetcher-20150205_183044_00014_xduyk.0.0-750 com.facebook.presto.server.HttpRemoteTask Error updating task 20150205_183044_00014_xduyk.0.0: Server returned SERVICE_UNAVAILABLE: http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.0.0?summarize: http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.0.0
2015-02-05T18:48:06.854+0000 WARN http-worker-818 com.facebook.presto.server.ThrowableMapper Request failed for /v1/statement/20150205_183044_00014_xduyk/842
com.facebook.presto.operator.PageTransportTimeoutException: Encountered too many errors talking to a worker node. The node may have crashed or be under too much load. This is probably a transient issue, so please retry your query in a few minutes. (http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.0.0/results/output.buffer.id/0 - requests failed for 60.00s)
at com.facebook.presto.operator.HttpPageBufferClient$2.onFailure(HttpPageBufferClient.java:330) ~[presto-main-0.92.jar:0.92]
at com.google.common.util.concurrent.Futures$6.run(Futures.java:1310) ~[guava-18.0.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:1.8.0_31]
at java.util.concurrent.FutureTask.run(Unknown Source) ~[na:1.8.0_31]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source) ~[na:1.8.0_31]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:1.8.0_31]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:1.8.0_31]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:1.8.0_31]
at java.lang.Thread.run(Unknown Source) [na:1.8.0_31]
Caused by: java.lang.RuntimeException: java.util.concurrent.TimeoutException
at com.google.common.base.Throwables.propagate(Throwables.java:160) ~[guava-18.0.jar:na]
at io.airlift.http.client.ResponseHandlerUtils.propagate(ResponseHandlerUtils.java:22) ~[http-client-0.99.jar:0.99]
at com.facebook.presto.operator.HttpPageBufferClient$PageResponseHandler.handleException(HttpPageBufferClient.java:439) ~[presto-main-0.92.jar:0.92]
at com.facebook.presto.operator.HttpPageBufferClient$PageResponseHandler.handleException(HttpPageBufferClient.java:426) ~[presto-main-0.92.jar:0.92]
at io.airlift.http.client.jetty.JettyHttpClient$JettyResponseFuture.failed(JettyHttpClient.java:513) ~[http-client-0.99.jar:0.99]
at io.airlift.http.client.jetty.JettyHttpClient$BufferingResponseListener.onComplete(JettyHttpClient.java:749) ~[http-client-0.99.jar:0.99]
at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:193) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:185) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:484) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.HttpReceiver.responseFailure(HttpReceiver.java:451) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.HttpReceiver.abort(HttpReceiver.java:516) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.http.HttpChannelOverHTTP.abort(HttpChannelOverHTTP.java:70) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:200) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:155) ~[jetty-client-9.2.2.v20140723.jar:9.2.2.v20140723]
at org.ecli
.....

Worker log:

2015-02-05T18:30:44.720+0000 DEBUG 20150205_183044_00014_xduyk.1.0-0-46 com.facebook.presto.plugin.jdbc.JdbcRecordCursor Executing: SELECT `type` FROM `service`.`items`

2015-02-05T18:51:28.983+0000 DEBUG exchange-client-6 com.facebook.presto.operator.HttpPageBufferClient Request to http://10.23.85.24:8080/v1/task/20150205_183044_00014_xduyk.1.0/results/20150205_183044_00014_xduyk.0.0/0 failed java.lang.RuntimeException: java.util.concurrent.TimeoutException
2015-02-05T18:52:11.550+0000 DEBUG task-notification-11 com.facebook.presto.execution.TaskStateMachine Task 20150205_183044_00014_xduyk.0.0 is ABORTED
2015-02-05T18:52:11.876+0000 DEBUG task-notification-12 com.facebook.presto.execution.TaskStateMachine Task 20150205_183044_00014_xduyk.1.0 is ABORTED
2015-02-05T18:54:52.259+0000 ERROR Discovery-0 io.airlift.discovery.client.CachingServiceSelector Cannot connect to discovery server for refresh (presto/general): Lookup of presto failed for http://mosaic1-dev.snc1:8080/v1/service/presto/general

Similar symptoms were reported and resolved here : https://groups.google.com/forum/#!searchin/presto-users/corodinator/presto-users/BbzkqaZR42M/WAiwGwPqk0UJ

Please help.

Thanks, Sasha