Alexey Kudinkin created HUDI-3691:
-------------------------------------
Summary: NPE in HoodieHiveSyncGlobalCommitTool
Key: HUDI-3691
URL: https://issues.apache.org/jira/browse/HUDI-3691
Project: Apache Hudi
Issue Type: Bug
Reporter: Alexey Kudinkin
Assignee: Rajesh Mahindra
Fix For: 0.11.0
In CI there are a lot of noisy NPEs w/in HoodieHiveSyncGlobalCommitTool tests,
which however do not fail the tests, like following:
{code:java}
28234 [main] ERROR org.apache.hudi.hive.replication.HiveSyncGlobalCommitTool -
Error while trying to commit replication state Failed in executing SQL CREATE
EXTERNAL TABLE IF NOT EXISTS `foo`.`bar`( `name` string, `favorite_number` int,
`favorite_color` string) PARTITIONED BY (`datestr` String) ROW FORMAT SERDE
'org.apache.hadoop.hive.ql.io.parquet.serde.ParquetHiveSerDe' WITH
SERDEPROPERTIES
('hoodie.query.as.ro.table'='false','path'='hdfs://localhost:33539/user/vsts/foo/bar')
STORED AS INPUTFORMAT 'org.apache.hudi.hadoop.HoodieParquetInputFormat'
OUTPUTFORMAT 'org.apache.hadoop.hive.ql.io.parquet.MapredParquetOutputFormat'
LOCATION 'hdfs://localhost:33539/user/vsts/foo/bar'
TBLPROPERTIES('spark.sql.sources.schema.partCol.0'='datestr','spark.sql.sources.schema.numParts'='1','spark.sql.sources.schema.numPartCols'='1','spark.sql.sources.provider'='hudi','spark.sql.sources.schema.part.0'='{"type":"struct","fields":[{"name":"name","type":"string","nullable":false,"metadata":{}},{"name":"favorite_number","type":"integer","nullable":false,"metadata":{}},{"name":"favorite_color","type":"string","nullable":false,"metadata":{}},{"name":"datestr","type":"string","nullable":false,"metadata":{}}]}')
2022-03-23T05:03:26.1208417Z org.apache.hudi.hive.HoodieHiveSyncException:
Failed in executing SQL CREATE EXTERNAL TABLE IF NOT EXISTS `foo`.`bar`( `name`
string, `favorite_number` int, `favorite_color` string) PARTITIONED BY
(`datestr` String) ROW FORMAT SERDE
'org.apache.hadoop.hive.ql.io.parquet.serde.ParquetHiveSerDe' WITH
SERDEPROPERTIES
('hoodie.query.as.ro.table'='false','path'='hdfs://localhost:33539/user/vsts/foo/bar')
STORED AS INPUTFORMAT 'org.apache.hudi.hadoop.HoodieParquetInputFormat'
OUTPUTFORMAT 'org.apache.hadoop.hive.ql.io.parquet.MapredParquetOutputFormat'
LOCATION 'hdfs://localhost:33539/user/vsts/foo/bar'
TBLPROPERTIES('spark.sql.sources.schema.partCol.0'='datestr','spark.sql.sources.schema.numParts'='1','spark.sql.sources.schema.numPartCols'='1','spark.sql.sources.provider'='hudi','spark.sql.sources.schema.part.0'='{"type":"struct","fields":[{"name":"name","type":"string","nullable":false,"metadata":{}},{"name":"favorite_number","type":"integer","nullable":false,"metadata":{}},{"name":"favorite_color","type":"string","nullable":false,"metadata":{}},{"name":"datestr","type":"string","nullable":false,"metadata":{}}]}')
2022-03-23T05:03:26.1210798Z at
org.apache.hudi.hive.ddl.JDBCExecutor.runSQL(JDBCExecutor.java:67)
2022-03-23T05:03:26.1211318Z at
org.apache.hudi.hive.ddl.QueryBasedDDLExecutor.createTable(QueryBasedDDLExecutor.java:84)
2022-03-23T05:03:26.1211842Z at
org.apache.hudi.hive.HoodieHiveClient.createTable(HoodieHiveClient.java:221)
2022-03-23T05:03:26.1212324Z at
org.apache.hudi.hive.HiveSyncTool.syncSchema(HiveSyncTool.java:266)
2022-03-23T05:03:26.1212803Z at
org.apache.hudi.hive.HiveSyncTool.syncHoodieTable(HiveSyncTool.java:207)
2022-03-23T05:03:26.1213317Z at
org.apache.hudi.hive.replication.GlobalHiveSyncTool.syncHoodieTable(GlobalHiveSyncTool.java:50)
2022-03-23T05:03:26.1213825Z at
org.apache.hudi.hive.HiveSyncTool.doSync(HiveSyncTool.java:151)
2022-03-23T05:03:26.1214328Z at
org.apache.hudi.hive.replication.GlobalHiveSyncTool.syncHoodieTable(GlobalHiveSyncTool.java:45)
2022-03-23T05:03:26.1214870Z at
org.apache.hudi.hive.replication.ReplicationStateSync.sync(ReplicationStateSync.java:57)
2022-03-23T05:03:26.1215425Z at
org.apache.hudi.hive.replication.HiveSyncGlobalCommitTool.commit(HiveSyncGlobalCommitTool.java:63)
2022-03-23T05:03:26.1216016Z at
org.apache.hudi.hive.TestHiveSyncGlobalCommitTool.testBasicRollback(TestHiveSyncGlobalCommitTool.java:117)
2022-03-23T05:03:26.1216573Z at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2022-03-23T05:03:26.1217003Z at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2022-03-23T05:03:26.1217520Z at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2022-03-23T05:03:26.1217981Z at
java.lang.reflect.Method.invoke(Method.java:498)
2022-03-23T05:03:26.1218435Z at
org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:688)
2022-03-23T05:03:26.1218962Z at
org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
2022-03-23T05:03:26.1219573Z at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
2022-03-23T05:03:26.1220180Z at
org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
2022-03-23T05:03:26.1220752Z at
org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
2022-03-23T05:03:26.1221334Z at
org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)
2022-03-23T05:03:26.1221954Z at
org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
2022-03-23T05:03:26.1222682Z at
org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
2022-03-23T05:03:26.1223317Z at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
2022-03-23T05:03:26.1223943Z at
org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
2022-03-23T05:03:26.1224551Z at
org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
2022-03-23T05:03:26.1225163Z at
org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
2022-03-23T05:03:26.1225725Z at
org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
2022-03-23T05:03:26.1226247Z at
org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
2022-03-23T05:03:26.1226848Z at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:212)
2022-03-23T05:03:26.1227549Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1228150Z at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:208)
2022-03-23T05:03:26.1228764Z at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:137)
2022-03-23T05:03:26.1229351Z at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:71)
2022-03-23T05:03:26.1229948Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
2022-03-23T05:03:26.1230546Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1231151Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
2022-03-23T05:03:26.1231698Z at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
2022-03-23T05:03:26.1232369Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
2022-03-23T05:03:26.1232968Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1233542Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
2022-03-23T05:03:26.1234104Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
2022-03-23T05:03:26.1234566Z at
java.util.ArrayList.forEach(ArrayList.java:1259)
2022-03-23T05:03:26.1235137Z at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
2022-03-23T05:03:26.1235825Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
2022-03-23T05:03:26.1236421Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1237019Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
2022-03-23T05:03:26.1237556Z at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
2022-03-23T05:03:26.1238106Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
2022-03-23T05:03:26.1238707Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1239286Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
2022-03-23T05:03:26.1239846Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
2022-03-23T05:03:26.1240371Z at
java.util.ArrayList.forEach(ArrayList.java:1259)
2022-03-23T05:03:26.1240942Z at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
2022-03-23T05:03:26.1241632Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
2022-03-23T05:03:26.1242228Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1242809Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
2022-03-23T05:03:26.1243349Z at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
2022-03-23T05:03:26.1401056Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
2022-03-23T05:03:26.1401737Z at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2022-03-23T05:03:26.1402501Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
2022-03-23T05:03:26.1403060Z at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
2022-03-23T05:03:26.1403717Z at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
2022-03-23T05:03:26.1404417Z at
org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
2022-03-23T05:03:26.1405026Z at
org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
2022-03-23T05:03:26.1405638Z at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:107)
2022-03-23T05:03:26.1406257Z at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:87)
2022-03-23T05:03:26.1406869Z at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:53)
2022-03-23T05:03:26.1407523Z at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:66)
2022-03-23T05:03:26.1408151Z at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:51)
2022-03-23T05:03:26.1408685Z at
org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:87)
2022-03-23T05:03:26.1409201Z at
org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:66)
2022-03-23T05:03:26.1409766Z at
org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:154)
2022-03-23T05:03:26.1410367Z at
org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:127)
2022-03-23T05:03:26.1410921Z at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:377)
2022-03-23T05:03:26.1411435Z at
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:138)
2022-03-23T05:03:26.1411918Z at
org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:465)
2022-03-23T05:03:26.1412388Z at
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:451)
2022-03-23T05:03:26.1412897Z Caused by:
org.apache.hive.service.cli.HiveSQLException: java.lang.RuntimeException:
java.lang.NullPointerException
2022-03-23T05:03:26.1413372Z at
org.apache.hive.jdbc.Utils.verifySuccess(Utils.java:267)
2022-03-23T05:03:26.1413803Z at
org.apache.hive.jdbc.Utils.verifySuccessWithInfo(Utils.java:253)
2022-03-23T05:03:26.1414272Z at
org.apache.hive.jdbc.HiveStatement.runAsyncOnServer(HiveStatement.java:313)
2022-03-23T05:03:26.1414740Z at
org.apache.hive.jdbc.HiveStatement.execute(HiveStatement.java:253)
2022-03-23T05:03:26.1415251Z at
org.apache.hudi.hive.ddl.JDBCExecutor.runSQL(JDBCExecutor.java:65)
2022-03-23T05:03:26.1415582Z ... 77 more
2022-03-23T05:03:26.1415923Z Caused by: java.lang.RuntimeException:
java.lang.RuntimeException: java.lang.NullPointerException
2022-03-23T05:03:26.1416479Z at
org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:89)
2022-03-23T05:03:26.1417019Z at
org.apache.hive.service.cli.session.HiveSessionProxy.access$000(HiveSessionProxy.java:36)
2022-03-23T05:03:26.1417551Z at
org.apache.hive.service.cli.session.HiveSessionProxy$1.run(HiveSessionProxy.java:63)
2022-03-23T05:03:26.1417990Z at
java.security.AccessController.doPrivileged(Native Method)
2022-03-23T05:03:26.1418365Z at
javax.security.auth.Subject.doAs(Subject.java:422)
2022-03-23T05:03:26.1418821Z at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
2022-03-23T05:03:26.1419333Z at
org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:59)
2022-03-23T05:03:26.1419789Z at
com.sun.proxy.$Proxy56.executeStatementAsync(Unknown Source)
2022-03-23T05:03:26.1420226Z at
org.apache.hive.service.cli.CLIService.executeStatementAsync(CLIService.java:310)
2022-03-23T05:03:26.1420807Z at
org.apache.hive.service.cli.thrift.ThriftCLIService.ExecuteStatement(ThriftCLIService.java:530)
2022-03-23T05:03:26.1421395Z at
org.apache.hive.service.rpc.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1437)
2022-03-23T05:03:26.1422003Z at
org.apache.hive.service.rpc.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1422)
2022-03-23T05:03:26.1422525Z at
org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
2022-03-23T05:03:26.1422973Z at
org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
2022-03-23T05:03:26.1423471Z at
org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
2022-03-23T05:03:26.1424010Z at
org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
2022-03-23T05:03:26.1424533Z at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2022-03-23T05:03:26.1425040Z at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2022-03-23T05:03:26.1425459Z at java.lang.Thread.run(Thread.java:750)
2022-03-23T05:03:26.1425825Z Caused by: java.lang.RuntimeException:
java.lang.NullPointerException
2022-03-23T05:03:26.1426284Z at
org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:89)
2022-03-23T05:03:26.1426811Z at
org.apache.hive.service.cli.session.HiveSessionProxy.access$000(HiveSessionProxy.java:36)
2022-03-23T05:03:26.1427351Z at
org.apache.hive.service.cli.session.HiveSessionProxy$1.run(HiveSessionProxy.java:63)
2022-03-23T05:03:26.1427799Z at
java.security.AccessController.doPrivileged(Native Method)
2022-03-23T05:03:26.1428170Z at
javax.security.auth.Subject.doAs(Subject.java:422)
2022-03-23T05:03:26.1428627Z at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
2022-03-23T05:03:26.1429141Z at
org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:59)
2022-03-23T05:03:26.1429590Z at
com.sun.proxy.$Proxy56.submitBackgroundOperation(Unknown Source)
2022-03-23T05:03:26.1430047Z at
org.apache.hive.service.cli.operation.SQLOperation.runInternal(SQLOperation.java:304)
2022-03-23T05:03:26.1430542Z at
org.apache.hive.service.cli.operation.Operation.run(Operation.java:320)
2022-03-23T05:03:26.1431063Z at
org.apache.hive.service.cli.session.HiveSessionImpl.executeStatementInternal(HiveSessionImpl.java:530)
2022-03-23T05:03:26.1431646Z at
org.apache.hive.service.cli.session.HiveSessionImpl.executeStatementAsync(HiveSessionImpl.java:517)
2022-03-23T05:03:26.1463349Z at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2022-03-23T05:03:26.1463809Z at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2022-03-23T05:03:26.1464508Z at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2022-03-23T05:03:26.1464962Z at
java.lang.reflect.Method.invoke(Method.java:498)
2022-03-23T05:03:26.1465410Z at
org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:78)
2022-03-23T05:03:26.1465787Z ... 18 more
2022-03-23T05:03:26.1466063Z Caused by: java.lang.NullPointerException: null
2022-03-23T05:03:26.1466505Z at
org.apache.hive.service.cli.session.SessionManager.submitBackgroundOperation(SessionManager.java:560)
2022-03-23T05:03:26.1467100Z at
org.apache.hive.service.cli.session.HiveSessionImpl.submitBackgroundOperation(HiveSessionImpl.java:552)
2022-03-23T05:03:26.1467593Z at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2022-03-23T05:03:26.1468019Z at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2022-03-23T05:03:26.1468529Z at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2022-03-23T05:03:26.1468987Z at
java.lang.reflect.Method.invoke(Method.java:498)
2022-03-23T05:03:26.1469437Z at
org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:78)
2022-03-23T05:03:26.1469883Z ... 34 more{code}
[https://dev.azure.com/apache-hudi-ci-org/apache-hudi-ci/_build/results?buildId=7211&view=logs&j=3272dbb2-0925-5f35-bae7-04e75ae62175&t=e3c8a1bc-8efe-5852-1800-3bd561aebfc8&l=1217]
We need to clarify if these failures are symptomatic of any real issues and if
otherwise we should just find the way to address them.
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
