[TAJO-1246] HBase info port conflict occasionally causes unit test failures in Jenkins CI

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 0.10.0
• Assignee: Hyunsik Choi
• Reporter: Hyunsik Choi
• Created: 13/Dec/14 03:06
• Updated: 15/Dec/14 09:27
• Resolved: 15/Dec/14 09:14

Description

See the title. The console log at https://builds.apache.org/job/Tajo-master-build/505/console shows the following errors during tests:

014-12-12 08:55:29,929 INFO: org.apache.zookeeper.server.NIOServerCnxnFactory (run(197)) - Accepted socket connection from /127.0.0.1:57385
2014-12-12 08:55:29,929 INFO: org.apache.zookeeper.ClientCnxn (primeConnection(852)) - Socket connection established to localhost/127.0.0.1:62942, initiating session
2014-12-12 08:55:29,935 INFO: org.apache.zookeeper.server.ZooKeeperServer (processConnectRequest(868)) - Client attempting to establish new session at /127.0.0.1:57385
2014-12-12 08:55:29,941 INFO: org.apache.zookeeper.server.persistence.FileTxnLog (append(199)) - Creating new log file: log.1
2014-12-12 08:55:29,951 INFO: org.apache.zookeeper.server.ZooKeeperServer (finishSessionInit(617)) - Established session 0x14a3db5c2640000 with negotiated timeout 40000 for client /127.0.0.1:57385
2014-12-12 08:55:29,951 INFO: org.apache.zookeeper.ClientCnxn (onConnected(1235)) - Session establishment complete on server localhost/127.0.0.1:62942, sessionid = 0x14a3db5c2640000, negotiated timeout = 40000
2014-12-12 08:55:30,313 INFO: org.mortbay.log (info(67)) - jetty-6.1.14
2014-12-12 08:55:30,328 INFO: org.mortbay.log (info(67)) - Extract jar:file:/home/jenkins/.m2/repository/org/apache/hbase/hbase-server/0.98.7-hadoop2/hbase-server-0.98.7-hadoop2.jar!/hbase-webapps/regionserver to /tmp/Jetty_0_0_0_0_46182_regionserver____ppeez9/webapp
2014-12-12 08:55:30,474 INFO: org.mortbay.log (info(67)) - Started HttpServer$SelectChannelConnectorWithSafeStartup@0.0.0.0:46182
2014-12-12 08:55:30,490 FATAL: org.apache.hadoop.hbase.master.HMaster (abort(2187)) - Unhandled exception. Starting shutdown.
java.net.BindException: Port in use: 0.0.0.0:60010
at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:783)
at org.apache.hadoop.http.HttpServer.start(HttpServer.java:727)
at org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:587)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.net.BindException: Address already in use
at sun.nio.ch.Net.bind(Native Method)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:124)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:59)
at org.mortbay.jetty.nio.SelectChannelConnector.open(SelectChannelConnector.java:216)
at org.apache.hadoop.http.HttpServer.openListener(HttpServer.java:779)
... 3 more
2014-12-12 08:55:30,493 INFO: org.apache.zookeeper.server.PrepRequestProcessor (pRequest2Txn(494)) - Processed session termination for sessionid: 0x14a3db5c2640000
2014-12-12 08:55:30,494 INFO: org.apache.zookeeper.ZooKeeper (close(684)) - Session: 0x14a3db5c2640000 closed
2014-12-12 08:55:30,494 INFO: org.apache.zookeeper.ClientCnxn (run(512)) - EventThread shut down
2014-12-12 08:55:30,495 INFO: org.apache.zookeeper.server.NIOServerCnxn (closeSock(1007)) - Closed socket connection for client /127.0.0.1:57385 which had sessionid 0x14a3db5c2640000
2014-12-12 08:56:00,523 ERROR: org.apache.hadoop.hbase.MiniHBaseCluster (init(229)) - Error starting cluster
java.lang.RuntimeException: Master not active after 30 seconds
at org.apache.hadoop.hbase.util.JVMClusterUtil.startup(JVMClusterUtil.java:190)
at org.apache.hadoop.hbase.LocalHBaseCluster.startup(LocalHBaseCluster.java:425)
at org.apache.hadoop.hbase.MiniHBaseCluster.init(MiniHBaseCluster.java:224)
at org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:93)
at org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:80)
at org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:67)
at org.apache.tajo.HBaseTestClusterUtil.startHBaseCluster(HBaseTestClusterUtil.java:108)
at org.apache.tajo.engine.query.TestHBaseTable.beforeClass(TestHBaseTable.java:67)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2014-12-12 08:56:00,527 INFO: org.apache.tajo.master.session.SessionManager (createSession(73)) - Session ba8873bd-ea15-4ad4-bea8-ce8222518aa9 is created.
2014-12-12 08:56:00,529 INFO: org.apache.tajo.master.GlobalEngine (updateQuery(483)) - SQL: CREATE DATABASE IF NOT EXISTS "TestHBaseTable"
2014-12-12 08:56:00,529 INFO: org.apache.tajo.master.GlobalEngine (createLogicalPlan(564)) - Non Optimized Query: