Created on 06-23-2021 01:28 AM - edited 06-23-2021 01:48 AM
I am using hive metatore version 3.1.0 in remote mode with Postgres as the underlying database. I recently upgraded from using embedded mode and noticed the following errors:
2021-06-22 11:44:04
Caused by: org.postgresql.util.PSQLException: ERROR: insert or update on table "KEY_CONSTRAINTS" violates foreign key constraint "KEY_CONSTRAINTS_FK3"
..
2021-06-22 09:44:08,978 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_databases: #
2021-06-22 09:44:08,978 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_databases: #
2021-06-22 09:44:08,952 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_foreign_keys : parentdb=null parenttbl=null foreigndb=default foreigntbl=hiveserver_runtime_stats
2021-06-22 09:44:08,951 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_foreign_keys : parentdb=null parenttbl=null foreigndb=default foreigntbl=hiveserver_runtime_stats
2021-06-22 09:44:08,945 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_unique_constraints : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,945 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_unique_constraints : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,940 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_primary_keys : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,939 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_primary_keys : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,933 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_primary_keys : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,933 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_primary_keys : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,927 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_not_null_constraints : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,926 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_not_null_constraints : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,870 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_table : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,870 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_table : tbl=hive.default.hiveserver_runtime_stats
2021-06-22 09:44:08,855 INFO [pool-6-thread-84] txn.TxnHandler (TxnHandler.java:openTxns(644)) - Added entries to MIN_HISTORY_LEVEL for current txns: ([1210814]) with min_open_txn: 1210814
2021-06-22 09:44:08,719 INFO [pool-6-thread-84] metastore.ObjectStore (ObjectStore.java:setConf(396)) - Initialized ObjectStore
2021-06-22 09:44:08,719 INFO [pool-6-thread-84] metastore.MetaStoreDirectSql (MetaStoreDirectSql.java:<init>(186)) - Using direct SQL, underlying DB is POSTGRES
2021-06-22 09:44:08,705 INFO [pool-6-thread-84] metastore.ObjectStore (ObjectStore.java:initializeHelper(481)) - ObjectStore, initialize called
2021-06-22 09:44:08,704 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:newRawStoreForConf(717)) - 84: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
2021-06-22 09:44:08,704 INFO [pool-6-thread-84] HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(347)) - ugi=hadoop ip=10.1.5.132 cmd=source:10.1.5.132 get_database: #default
2021-06-22 09:44:08,704 INFO [pool-6-thread-84] metastore.HiveMetaStore (HiveMetaStore.java:logInfo(895)) - 84: source:10.1.5.132 get_database: #default
2021-06-22 09:44:04,989 INFO [pool-6-thread-110] txn.TxnHandler (TxnHandler.java:commitTxn(1015)) - Removed committed transaction: (1210813) from MIN_HISTORY_LEVEL
2021-06-22 09:44:04,982 INFO [pool-6-thread-110] txn.TxnHandler (TxnHandler.java:commitTxn(1000)) - Expected to move at least one record from txn_components to completed_txn_components when committing txn! txnid:1210813
... 43 more
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:394)
at org.datanucleus.store.rdbms.table.TableImpl.validateForeignKeys(TableImpl.java:468)
at org.datanucleus.store.rdbms.table.TableImpl.createForeignKeys(TableImpl.java:522)
at org.datanucleus.store.rdbms.table.AbstractTable.executeDdlStatement(AbstractTable.java:879)
at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)
at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:266)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:270)
at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:293)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:307)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:308)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2183)
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2440)
Detail: Key (PARENT_CD_ID)=(1450) is not present in table "CDS".
Caused by: org.postgresql.util.PSQLException: ERROR: insert or update on table "KEY_CONSTRAINTS" violates foreign key constraint "KEY_CONSTRAINTS_FK3"
at java.lang.Thread.run(Thread.java:748)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
at org.apache.hadoop.hive.metastore.TUGIBasedProcessor.process(TUGIBasedProcessor.java:119)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1729)
at javax.security.auth.Subject.doAs(Subject.java:422)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:107)
at org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:111)
at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$drop_table_with_environment_context.getResult(ThriftHiveMetastore.java:15052)
at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$drop_table_with_environment_context.getResult(ThriftHiveMetastore.java:15068)
at com.sun.proxy.$Proxy26.drop_table_with_environment_context(Unknown Source)
at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.drop_table_with_environment_context(HiveMetaStore.java:2697)
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.drop_table_core(HiveMetaStore.java:2526)
at com.sun.proxy.$Proxy25.dropTable(Unknown Source)
at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:97)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at org.apache.hadoop.hive.metastore.ObjectStore.dropTable(ObjectStore.java:1407)
at org.apache.hadoop.hive.metastore.ObjectStore.listAllTableConstraintsWithOptionalConstraintName(ObjectStore.java:1487)
at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:228)
at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:368)
at org.datanucleus.store.query.Query.executeWithArray(Query.java:1744)
at org.datanucleus.store.query.Query.executeQuery(Query.java:1816)
at org.datanucleus.store.rdbms.query.JDOQLQuery.compileInternal(JDOQLQuery.java:347)
at org.datanucleus.store.rdbms.query.JDOQLQuery.compileQueryFull(JDOQLQuery.java:865)
at org.datanucleus.store.rdbms.query.RDBMSQueryUtils.getStatementForCandidates(RDBMSQueryUtils.java:425)
at org.datanucleus.store.rdbms.RDBMSStoreManager.getDatastoreClass(RDBMSStoreManager.java:672)
at org.datanucleus.store.rdbms.RDBMSStoreManager.manageClasses(RDBMSStoreManager.java:1627)
at org.datanucleus.store.rdbms.AbstractSchemaTransaction.execute(AbstractSchemaTransaction.java:119)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.run(RDBMSStoreManager.java:2896)
at org.datanucleus.store.rdbms.RDBMSStoreManager$ClassAdder.performTablesValidation(RDBMSStoreManager.java:3471)
at org.datanucleus.store.rdbms.table.ClassTable.validateConstraints(ClassTable.java:3576)
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:395)
at org.datanucleus.store.rdbms.table.TableImpl.validateIndices(TableImpl.java:566)
at org.datanucleus.store.rdbms.table.TableImpl.getExistingIndices(TableImpl.java:1116)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getSchemaData(RDBMSSchemaHandler.java:333)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:783)
at org.datanucleus.store.rdbms.schema.RDBMSSchemaHandler.getRDBMSTableIndexInfoForTable(RDBMSSchemaHandler.java:813)
at org.apache.commons.dbcp.DelegatingDatabaseMetaData.getIndexInfo(DelegatingDatabaseMetaData.java:327)
at org.postgresql.jdbc.PgDatabaseMetaData.getIndexInfo(PgDatabaseMetaData.java:2401)
at org.postgresql.jdbc.PgStatement.executeQuery(PgStatement.java:224)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:270)
at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:293)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:307)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:308)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2183)
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2440)
org.postgresql.util.PSQLException: ERROR: current transaction is aborted, commands ignored until end of transaction block
Nested Throwables StackTrace:
... 43 more
at org.datanucleus.store.rdbms.table.TableImpl.validateConstraints(TableImpl.java:394)
at org.datanucleus.store.rdbms.table.TableImpl.validateForeignKeys(TableImpl.java:468)
at org.datanucleus.store.rdbms.table.TableImpl.createForeignKeys(TableImpl.java:522)
at org.datanucleus.store.rdbms.table.AbstractTable.executeDdlStatement(AbstractTable.java:879)
at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)
at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:266)
An analysis of the error shows that some process is writing to the table "KEY_CONSTRAINTS" but not adding the corresponding primary key to the table "CDS"
I attempted to manually add the missing keys to the CDS table, but a couple of hours later the problem returns only with a new set of keys.
At this stage, I'm not sure what is causing this issue? What is perhaps the upgrade to using remote mode or a previous upgrade from 3.0.0 to 3.1.0 and how do I fix this?
Here we can see the tables affected
My questions are:
I would really appreciate any comments and answers to the above questions or any useful information to help me debug further
Created 07-05-2021 09:50 AM
I believe this issue is the result of upgrade.
Did you upgrade from 3.0.1 to 3.1.0 ?
In which version you were using Embedded mode ? Can you recreate the metadata if this is not production and check ?