You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@livy.apache.org by "Marco Gaido (Jira)" <ji...@apache.org> on 2020/02/15 21:45:00 UTC
[jira] [Resolved] (LIVY-745) more than 11 concurrent clients lead
to java.io.IOException: Unable to connect to provided ports 10000~10010
[ https://issues.apache.org/jira/browse/LIVY-745?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Marco Gaido resolved LIVY-745.
------------------------------
Fix Version/s: 0.7.0
Assignee: Wing Yew Poon
Resolution: Fixed
Issue resolved by pull request https://github.com/apache/incubator-livy/pull/275.
> more than 11 concurrent clients lead to java.io.IOException: Unable to connect to provided ports 10000~10010
> ------------------------------------------------------------------------------------------------------------
>
> Key: LIVY-745
> URL: https://issues.apache.org/jira/browse/LIVY-745
> Project: Livy
> Issue Type: Bug
> Components: RSC
> Affects Versions: 0.6.0
> Reporter: Wing Yew Poon
> Assignee: Wing Yew Poon
> Priority: Major
> Fix For: 0.7.0
>
> Time Spent: 20m
> Remaining Estimate: 0h
>
> In testing scalability of the Livy Thrift server, I am simultaneously starting multiple connections to it. When there are more than 11 connections started simultaneously, the 12th (and subsequent) connection will fail with:
> {noformat}
> 2020-01-10 13:53:28,686 ERROR org.apache.livy.thriftserver.LivyExecuteStatementOperation: Error running hive query:
> org.apache.hive.service.cli.HiveSQLException: java.lang.RuntimeException: java.io.IOException: Unable to connect to provided ports 10000~10010
> {noformat}
> Here is the excerpt from the Livy server log:
> {noformat}
> 2020-01-10 13:53:28,138 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 0: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> ...
> 2020-01-10 13:53:28,147 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 1: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> ...
> 2020-01-10 13:53:28,196 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 2: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> ...
> 2020-01-10 13:53:28,247 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 3: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> ...
> 2020-01-10 13:53:28,304 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 4: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,329 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,329 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,329 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,329 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,329 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10000
> ...
> 2020-01-10 13:53:28,331 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10001
> ...
> 2020-01-10 13:53:28,335 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,335 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,335 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,338 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10002
> 2020-01-10 13:53:28,338 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> ...
> 2020-01-10 13:53:28,339 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,341 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10003
> ...
> 2020-01-10 13:53:28,341 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> ...
> 2020-01-10 13:53:28,343 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10004
> ...
> 2020-01-10 13:53:28,362 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 5: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,367 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,369 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,371 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,373 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,376 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,379 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10005
> ...
> 2020-01-10 13:53:28,412 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 6: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> ...
> 2020-01-10 13:53:28,416 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> ...
> 2020-01-10 13:53:28,418 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,419 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,420 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,422 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,423 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10005 Address already in use
> 2020-01-10 13:53:28,424 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10006
> ...
> 2020-01-10 13:53:28,462 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 7: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,466 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,468 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,470 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,471 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,472 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,473 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10005 Address already in use
> 2020-01-10 13:53:28,475 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10006 Address already in use
> 2020-01-10 13:53:28,476 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10007
> ...
> 2020-01-10 13:53:28,510 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 8: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,513 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,514 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,515 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,522 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,524 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,525 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10005 Address already in use
> 2020-01-10 13:53:28,526 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10006 Address already in use
> 2020-01-10 13:53:28,527 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10007 Address already in use
> 2020-01-10 13:53:28,527 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10008
> ...
> 2020-01-10 13:53:28,561 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 9: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,564 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,565 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,565 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,567 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,568 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,568 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10005 Address already in use
> 2020-01-10 13:53:28,569 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10006 Address already in use
> 2020-01-10 13:53:28,569 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10007 Address already in use
> 2020-01-10 13:53:28,570 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10008 Address already in use
> 2020-01-10 13:53:28,570 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10009
> ...
> 2020-01-10 13:53:28,611 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 10: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,614 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,615 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,616 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,617 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,618 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,618 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10005 Address already in use
> 2020-01-10 13:53:28,619 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10006 Address already in use
> 2020-01-10 13:53:28,620 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10007 Address already in use
> 2020-01-10 13:53:28,620 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10008 Address already in use
> 2020-01-10 13:53:28,621 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10009 Address already in use
> 2020-01-10 13:53:28,621 INFO org.apache.livy.rsc.rpc.RpcServer: Connected to the port 10010
> ...
> 2020-01-10 13:53:28,661 INFO org.apache.livy.server.interactive.InteractiveSession$: Creating Interactive session 11: [owner: systest, request: [kind: spark, proxyUser: None, heartbeatTimeoutInSecond: 0]]
> 2020-01-10 13:53:28,664 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10000 Address already in use
> 2020-01-10 13:53:28,664 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10001 Address already in use
> 2020-01-10 13:53:28,665 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10002 Address already in use
> 2020-01-10 13:53:28,666 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10003 Address already in use
> 2020-01-10 13:53:28,667 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10004 Address already in use
> 2020-01-10 13:53:28,677 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10005 Address already in use
> 2020-01-10 13:53:28,678 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10006 Address already in use
> 2020-01-10 13:53:28,679 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10007 Address already in use
> 2020-01-10 13:53:28,679 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10008 Address already in use
> 2020-01-10 13:53:28,679 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10009 Address already in use
> 2020-01-10 13:53:28,680 DEBUG org.apache.livy.rsc.rpc.RpcServer: RPC not able to connect port 10010 Address already in use
> 2020-01-10 13:53:28,683 INFO org.apache.livy.thriftserver.LivyExecuteStatementOperation: (Error executing query, currentState RUNNING, ,java.lang.RuntimeException: java.io.IOException: Unable to connect to provided ports 10000~10010)
> 2020-01-10 13:53:28,686 ERROR org.apache.livy.thriftserver.LivyExecuteStatementOperation: Error running hive query:
> org.apache.hive.service.cli.HiveSQLException: java.lang.RuntimeException: java.io.IOException: Unable to connect to provided ports 10000~10010
> at org.apache.livy.thriftserver.LivyExecuteStatementOperation.execute(LivyExecuteStatementOperation.scala:147)
> at org.apache.livy.thriftserver.LivyExecuteStatementOperation$$anon$1$$anon$2.run(LivyExecuteStatementOperation.scala:97)
> at org.apache.livy.thriftserver.LivyExecuteStatementOperation$$anon$1$$anon$2.run(LivyExecuteStatementOperation.scala:94)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:422)
> at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1876)
> at org.apache.livy.thriftserver.LivyExecuteStatementOperation$$anon$1.run(LivyExecuteStatementOperation.scala:107)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.lang.RuntimeException: java.io.IOException: Unable to connect to provided ports 10000~10010
> at org.apache.livy.rsc.Utils.propagate(Utils.java:60)
> at org.apache.livy.rsc.RSCClientFactory.createClient(RSCClientFactory.java:81)
> at org.apache.livy.LivyClientBuilder.build(LivyClientBuilder.java:130)
> at org.apache.livy.server.interactive.InteractiveSession$$anonfun$2.apply(InteractiveSession.scala:114)
> at org.apache.livy.server.interactive.InteractiveSession$$anonfun$2.apply(InteractiveSession.scala:84)
> at scala.Option.orElse(Option.scala:289)
> at org.apache.livy.server.interactive.InteractiveSession$.create(InteractiveSession.scala:84)
> at org.apache.livy.thriftserver.LivyThriftSessionManager$$anonfun$4.apply(LivyThriftSessionManager.scala:229)
> at org.apache.livy.thriftserver.LivyThriftSessionManager$$anonfun$4.apply(LivyThriftSessionManager.scala:227)
> at org.apache.livy.thriftserver.LivyThriftSessionManager.org$apache$livy$thriftserver$LivyThriftSessionManager$$getOrCreateLivySession(LivyThriftSessionManager.scala:185)
> at org.apache.livy.thriftserver.LivyThriftSessionManager$$anonfun$5$$anon$1.run(LivyThriftSessionManager.scala:248)
> at org.apache.livy.thriftserver.LivyThriftSessionManager$$anonfun$5$$anon$1.run(LivyThriftSessionManager.scala:245)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:422)
> at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1876)
> at org.apache.livy.thriftserver.LivyThriftSessionManager$$anonfun$5.apply(LivyThriftSessionManager.scala:245)
> at org.apache.livy.thriftserver.LivyThriftSessionManager$$anonfun$5.apply(LivyThriftSessionManager.scala:241)
> at scala.concurrent.impl.Future$PromiseCompletingRunnable.liftedTree1$1(Future.scala:24)
> at scala.concurrent.impl.Future$PromiseCompletingRunnable.run(Future.scala:24)
> at scala.concurrent.impl.ExecutionContextImpl$AdaptedForkJoinTask.exec(ExecutionContextImpl.scala:121)
> at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
> at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
> at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
> at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
> Caused by: java.io.IOException: Unable to connect to provided ports 10000~10010
> at org.apache.livy.rsc.rpc.RpcServer.<init>(RpcServer.java:101)
> at org.apache.livy.rsc.RSCClientFactory.ref(RSCClientFactory.java:98)
> at org.apache.livy.rsc.RSCClientFactory.createClient(RSCClientFactory.java:71)
> ... 22 more
> {noformat}
> As can be seen, the first 5 connections (session 0 to session 4) are created almost at the same time, and after some jostling, claim ports 10000 to 10004. The log then shows subsequent connections trying the ports from 10000 on up until they find one that is not in use. The last successful one is session 10, which claims port 10010. After that, session 11 fails.
> The port range (10000~10010) is configurable, but I'm using the default.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)