[
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)
