hive-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Stephen Sprague <sprag...@gmail.com>
Subject metastore (mysql) connection problems - hive v0.12
Date Wed, 18 Dec 2013 01:11:20 GMT
hi guys,
I'm pretty much at my wits end on this one. i'm using hive v0.12 against a
mysql metastore.   the error manifests itself (mostly randomly which is the
problem) as this error in the client:

2013-12-17 16:54:03,158 ERROR metastore.RetryingRawStore
(RetryingRawStore.java:invoke(146)) - JDO datastore error. Retrying
metastore command after 1000 ms (attempt 1 of 1)
2013-12-17 16:54:04,345 ERROR metastore.RetryingHMSHandler
(RetryingHMSHandler.java:invoke(141)) -
MetaException(message:java.lang.RuntimeException: commitTransaction was
called but openTransactionCalls = 0. This probably indicates that there are
unbalanced calls to openTransaction/commitTransaction)


but i believe this to be just a symptom of something happening further
upstream.


examining the hive.log file for this useer (under /tmp/<user>/hive.log) i
find this hideous traceback with "bonecp" being the focus of attention.
There's nothing wrong with the mysql server metastore especially given it
works sometimes.  to me i think it has something to do with the connection
pooling logic but that's only speculation.

before i surrender and rollback to a previous version i ask:  Has anyone
encountered this before?  Or are there any nuggets in the traceback worthy
of insight?

thanks,
Stephen.


2013-12-17 16:54:03,142 ERROR bonecp.ConnectionHandle
(ConnectionHandle.java:markPossiblyBroken(297)) - Database access problem.
Killing off all remaining connections in the connection pool. SQL State =
08S01
2013-12-17 16:54:03,144 ERROR bonecp.ConnectionHandle
(ConnectionHandle.java:markPossiblyBroken(297)) - Database access problem.
Killing off all remaining connections in the connection pool. SQL State =
08007
2013-12-17 16:54:03,146 ERROR bonecp.ConnectionHandle
(ConnectionHandle.java:markPossiblyBroken(297)) - Database access problem.
Killing off all remaining connections in the connection pool. SQL State =
08007
2013-12-17 16:54:03,147 ERROR bonecp.ConnectionHandle
(ConnectionHandle.java:markPossiblyBroken(297)) - Database access problem.
Killing off all remaining connections in the connection pool. SQL State =
08007
2013-12-17 16:54:03,148 ERROR bonecp.BoneCP
(BoneCP.java:terminateAllConnections(199)) - Error in attempting to close
connection
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException:
Communications link failure during rollback(). Transaction resolution
unknown.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
        at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
        at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4730)
        at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4325)
        at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1557)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:396)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:404)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:404)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.getTransactionIsolation(ConnectionHandle.java:635)
        at
org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl.getConnection(ConnectionFactoryImpl.java:422)
        at
org.datanucleus.store.rdbms.SQLController.getStatementForQuery(SQLController.java:316)
        at
org.datanucleus.store.rdbms.SQLController.getStatementForQuery(SQLController.java:300)
        at
org.datanucleus.store.rdbms.valuegenerator.SequenceTable.getNextVal(SequenceTable.java:194)
        at
org.datanucleus.store.rdbms.valuegenerator.TableGenerator.reserveBlock(TableGenerator.java:190)
        at
org.datanucleus.store.valuegenerator.AbstractGenerator.reserveBlock(AbstractGenerator.java:305)
        at
org.datanucleus.store.rdbms.valuegenerator.AbstractRDBMSGenerator.obtainGenerationBlock(AbstractRDBMSGenerator.java:98)
        at
org.datanucleus.store.valuegenerator.AbstractGenerator.obtainGenerationBlock(AbstractGenerator.java:197)
        at
org.datanucleus.store.valuegenerator.AbstractGenerator.next(AbstractGenerator.java:105)
        at
org.datanucleus.store.rdbms.RDBMSStoreManager.getStrategyValueForGenerator(RDBMSStoreManager.java:2019)
        at
org.datanucleus.store.AbstractStoreManager.getStrategyValue(AbstractStoreManager.java:1385)
        at
org.datanucleus.ExecutionContextImpl.newObjectId(ExecutionContextImpl.java:3727)
        at
org.datanucleus.state.JDOStateManager.setIdentity(JDOStateManager.java:2574)
        at
org.datanucleus.state.JDOStateManager.initialiseForPersistentNew(JDOStateManager.java:526)
        at
org.datanucleus.state.ObjectProviderFactoryImpl.newForPersistentNew(ObjectProviderFactoryImpl.java:202)
        at
org.datanucleus.ExecutionContextImpl.newObjectProviderForPersistentNew(ExecutionContextImpl.java:1326)
        at
org.datanucleus.ExecutionContextImpl.persistObjectInternal(ExecutionContextImpl.java:2123)
        at
org.datanucleus.ExecutionContextImpl.persistObjectInternal(ExecutionContextImpl.java:2212)
        at
org.datanucleus.store.rdbms.mapping.java.PersistableMapping.setObjectAsValue(PersistableMapping.java:567)
        at
org.datanucleus.store.rdbms.mapping.java.PersistableMapping.setObject(PersistableMapping.java:326)
        at
org.datanucleus.store.rdbms.fieldmanager.ParameterSetter.storeObjectField(ParameterSetter.java:193)
        at
org.datanucleus.state.JDOStateManager.providedObjectField(JDOStateManager.java:1272)
        at
org.apache.hadoop.hive.metastore.model.MTable.jdoProvideField(MTable.java)
        at
org.apache.hadoop.hive.metastore.model.MTable.jdoProvideFields(MTable.java)
        at
org.datanucleus.state.JDOStateManager.provideFields(JDOStateManager.java:1349)
        at
org.datanucleus.store.rdbms.request.InsertRequest.execute(InsertRequest.java:289)
        at
org.datanucleus.store.rdbms.RDBMSPersistenceHandler.insertTable(RDBMSPersistenceHandler.java:167)
        at
org.datanucleus.store.rdbms.RDBMSPersistenceHandler.insertObject(RDBMSPersistenceHandler.java:143)
        at
org.datanucleus.state.JDOStateManager.internalMakePersistent(JDOStateManager.java:3777)
        at
org.datanucleus.state.JDOStateManager.makePersistent(JDOStateManager.java:3753)
        at
org.datanucleus.ExecutionContextImpl.persistObjectInternal(ExecutionContextImpl.java:2124)
        at
org.datanucleus.ExecutionContextImpl.persistObjectWork(ExecutionContextImpl.java:1972)
        at
org.datanucleus.ExecutionContextImpl.persistObject(ExecutionContextImpl.java:1820)
        at
org.datanucleus.ExecutionContextThreadedImpl.persistObject(ExecutionContextThreadedImpl.java:217)
        at
org.datanucleus.api.jdo.JDOPersistenceManager.jdoMakePersistent(JDOPersistenceManager.java:727)
        at
org.datanucleus.api.jdo.JDOPersistenceManager.makePersistent(JDOPersistenceManager.java:752)
        at
org.apache.hadoop.hive.metastore.ObjectStore.createTable(ObjectStore.java:648)
        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.apache.hadoop.hive.metastore.RetryingRawStore.invoke(RetryingRawStore.java:124)
        at $Proxy4.createTable(Unknown Source)
        at
org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_table_core(HiveMetaStore.java:1074)
        at
org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_table_with_environment_context(HiveMetaStore.java:1107)
        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.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:103)
        at $Proxy9.create_table_with_environment_context(Unknown Source)
        at
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.createTable(HiveMetaStoreClient.java:482)
        at
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.createTable(HiveMetaStoreClient.java:471)
        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.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:89)
        at $Proxy10.createTable(Unknown Source)
        at
org.apache.hadoop.hive.ql.metadata.Hive.createTable(Hive.java:596)
        at
org.apache.hadoop.hive.ql.exec.DDLTask.createTable(DDLTask.java:3661)
        at org.apache.hadoop.hive.ql.exec.DDLTask.execute(DDLTask.java:252)
        at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:151)
        at
org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:65)
        at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:1414)
        at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1192)
        at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1020)
        at org.apache.hadoop.hive.ql.Driver.run(Driver.java:888)
        at
org.apache.hadoop.hive.service.HiveServer$HiveServerHandler.execute(HiveServer.java:198)
        at
org.apache.hadoop.hive.service.ThriftHive$Processor$execute.getResult(ThriftHive.java:644)
        at
org.apache.hadoop.hive.service.ThriftHive$Processor$execute.getResult(ThriftHive.java:628)
        at
org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
        at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
        at
org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:206)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
2013-12-17 16:54:03,153 ERROR bonecp.BoneCP
(BoneCP.java:terminateAllConnections(199)) - Error in attempting to close
connection
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException:
Communications link failure during rollback(). Transaction resolution
unknown.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
        at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
        at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4730)
        at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4325)
        at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1557)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:396)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:404)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:404)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:404)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.internalClose(ConnectionHandle.java:404)
        at com.jolbox.bonecp.BoneCP.terminateAllConnections(BoneCP.java:197)
        at
com.jolbox.bonecp.ConnectionHandle.markPossiblyBroken(ConnectionHandle.java:298)
        at
com.jolbox.bonecp.ConnectionHandle.getTransactionIsolation(ConnectionHandle.java:635)
        at
org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl.getConnection(ConnectionFactoryImpl.java:422)
        at
org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl.getXAResource(ConnectionFactoryImpl.java:356)
        at
org.datanucleus.store.connection.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:328)
        at
org.datanucleus.store.connection.AbstractConnectionFactory.getConnection(AbstractConnectionFactory.java:64)
        at
org.datanucleus.store.AbstractStoreManager.getConnection(AbstractStoreManager.java:429)
        at
org.datanucleus.store.AbstractStoreManager.getConnection(AbstractStoreManager.java:395)
        at
org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:607)
        at org.datanucleus.store.query.Query.executeQuery(Query.java:1786)
        at
org.datanucleus.store.query.Query.executeWithArray(Query.java:1672)
        at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:266)
        at
org.apache.hadoop.hive.metastore.ObjectStore.getMTable(ObjectStore.java:826)
        at
org.apache.hadoop.hive.metastore.ObjectStore.getTable(ObjectStore.java:760)
        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.apache.hadoop.hive.metastore.RetryingRawStore.invoke(RetryingRawStore.java:124)
        at $Proxy12.getTable(Unknown Source)
        at
org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.get_table(HiveMetaStore.java:1371)
        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.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:103)
        at $Proxy13.get_table(Unknown Source)
        at
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.getTable(HiveMetaStoreClient.java:854)
        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.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:89)
        at $Proxy14.getTable(Unknown Source)
        at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:950)
        at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:892)
        at
org.apache.hadoop.hive.ql.exec.MoveTask.execute(MoveTask.java:245)
        at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:151)
        at
org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:65)
        at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:1414)
        at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1192)
        at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1020)
        at org.apache.hadoop.hive.ql.Driver.run(Driver.java:888)
        at
org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:259)
        at
org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:216)
        at
org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:413)
        at
org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:781)
        at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:675)
        at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:614)
        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.apache.hadoop.util.RunJar.main(RunJar.java:208)

Mime
View raw message