[STORM-2841] testNoAcksIfFlushFails UT fails with NullPointerException - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Test
Status: Resolved
Priority: Major
Resolution: Fixed
Affects Version/s: None
Fix Version/s: 2.0.0, 1.2.1, 1.1.3, 1.0.7
Component/s: None
Labels:
- pull-request-available

Description

testNoAcksIfFlushFails UT fails with NPE

java.lang.NullPointerException: null
	at org.apache.storm.hive.bolt.HiveBolt.flushAllWriters(HiveBolt.java:207)
	at org.apache.storm.hive.bolt.TestHiveBolt.testNoAcksIfFlushFails(TestHiveBolt.java:322)

Standard Output

60488 [main] INFO  h.metastore - Mestastore configuration hive.metastore.filter.hook changed from org.apache.hadoop.hive.ql.security.authorization.plugin.AuthorizationMetaStoreFilterHook to org.apache.hadoop.hive.metastore.DefaultMetaStoreFilterHookImpl
60489 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: Shutting down the object store...
60489 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=Shutting down the object store...	
60489 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: Metastore shutdown complete.
60489 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=Metastore shutdown complete.	
60497 [main] INFO  o.a.h.h.q.s.SessionState - Created local directory: /tmp/75acc3af-f90e-4ab2-888c-a8ad29383128_resources
60499 [main] INFO  o.a.h.h.q.s.SessionState - Created HDFS directory: /tmp/hive/nobody/75acc3af-f90e-4ab2-888c-a8ad29383128
60501 [main] INFO  o.a.h.h.q.s.SessionState - Created local directory: /tmp/nobody/75acc3af-f90e-4ab2-888c-a8ad29383128
60503 [main] INFO  o.a.h.h.q.s.SessionState - Created HDFS directory: /tmp/hive/nobody/75acc3af-f90e-4ab2-888c-a8ad29383128/_tmp_space.db
60793 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_table_names_by_filter: db = testdb, filter = 
60793 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_table_names_by_filter: db = testdb, filter = 	
60847 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
60848 [main] INFO  o.a.h.h.m.ObjectStore - ObjectStore, initialize called
60864 [main] INFO  D.Persistence - Property hive.metastore.integral.jdo.pushdown unknown - will be ignored
60864 [main] INFO  D.Persistence - Property datanucleus.cache.level2 unknown - will be ignored
61370 [main] INFO  o.a.h.h.m.ObjectStore - Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,StorageDescriptor,SerDeInfo,Partition,Database,Type,FieldSchema,Order"
61711 [main] INFO  o.a.h.h.m.MetaStoreDirectSql - Using direct SQL, underlying DB is DERBY
61711 [main] INFO  o.a.h.h.m.ObjectStore - Initialized ObjectStore
61716 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_table : db=testdb tbl=test_table
61716 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_table : db=testdb tbl=test_table	
61738 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: drop_table : db=testdb tbl=test_table
61738 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=drop_table : db=testdb tbl=test_table	
62053 [main] INFO  h.m.hivemetastoressimpl - deleting  raw:/tmp/junit2860976527054408251/testdb.db/test_table
62062 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_database: testdb
62063 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_database: testdb	
62068 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: drop_database: testdb
62068 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=drop_database: testdb	
62069 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_all_tables: db=testdb
62069 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_all_tables: db=testdb	
62073 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_functions: db=testdb pat=*
62073 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_functions: db=testdb pat=*	
62103 [main] INFO  o.a.h.h.m.ObjectStore - Dropping database testdb along with all tables
62141 [main] INFO  h.m.hivemetastoressimpl - deleting  raw:/tmp/junit2860976527054408251/testdb.db
62148 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
62148 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
62149 [main] INFO  o.a.h.h.q.Driver - We are setting the hadoop caller context from  to nobody_20171128150454_9a730ff0-d279-4037-a1c9-4b3c28ff0a90
62149 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
62149 [main] INFO  h.q.p.ParseDriver - Parsing command: create database IF NOT EXISTS testdb location 'raw:///tmp/junit8935893841909704896/testdb.db'
62149 [main] INFO  h.q.p.ParseDriver - Parse Completed
62149 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=parse start=1511881494579 end=1511881494579 duration=0 from=org.apache.hadoop.hive.ql.Driver>
62149 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
62151 [main] INFO  o.a.h.h.q.Driver - Semantic Analysis Completed
62151 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=semanticAnalyze start=1511881494579 end=1511881494581 duration=2 from=org.apache.hadoop.hive.ql.Driver>
62151 [main] INFO  o.a.h.h.q.Driver - Returning Hive schema: Schema(fieldSchemas:null, properties:null)
62151 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=compile start=1511881494578 end=1511881494581 duration=3 from=org.apache.hadoop.hive.ql.Driver>
62151 [main] INFO  o.a.h.h.q.Driver - We are resetting the hadoop caller context to 
62151 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=acquireReadWriteLocks from=org.apache.hadoop.hive.ql.Driver>
62151 [main] INFO  o.a.h.h.q.l.DbTxnManager - Setting lock request transaction to txnid:0 for queryId=nobody_20171128150454_9a730ff0-d279-4037-a1c9-4b3c28ff0a90
62151 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=acquireReadWriteLocks start=1511881494581 end=1511881494581 duration=0 from=org.apache.hadoop.hive.ql.Driver>
62151 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
62152 [main] INFO  o.a.h.h.q.Driver - Setting caller context to query id nobody_20171128150454_9a730ff0-d279-4037-a1c9-4b3c28ff0a90
62152 [main] INFO  o.a.h.h.q.Driver - Starting command(queryId=nobody_20171128150454_9a730ff0-d279-4037-a1c9-4b3c28ff0a90): create database IF NOT EXISTS testdb location 'raw:///tmp/junit8935893841909704896/testdb.db'
62152 [main] INFO  o.a.h.h.q.s.a.p.s.SQLStdHiveAccessController - Created SQLStdHiveAccessController for session context : HiveAuthzSessionContext [sessionString=75acc3af-f90e-4ab2-888c-a8ad29383128, clientType=HIVECLI]
62152 [main] INFO  h.metastore - Mestastore configuration hive.metastore.filter.hook changed from org.apache.hadoop.hive.metastore.DefaultMetaStoreFilterHookImpl to org.apache.hadoop.hive.ql.security.authorization.plugin.AuthorizationMetaStoreFilterHook
62152 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: Shutting down the object store...
62152 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=Shutting down the object store...	
62153 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: Metastore shutdown complete.
62153 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=Metastore shutdown complete.	
62153 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
62153 [main] INFO  o.a.h.h.q.Driver - Starting task [Stage-0:DDL] in serial mode
62153 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: create_database: Database(name:testdb, description:null, locationUri:raw:/tmp/junit8935893841909704896/testdb.db, parameters:null, ownerName:nobody, ownerType:USER)
62154 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=create_database: Database(name:testdb, description:null, locationUri:raw:/tmp/junit8935893841909704896/testdb.db, parameters:null, ownerName:nobody, ownerType:USER)	
62199 [main] WARN  o.a.h.h.c.HiveConf - HiveConf of name hive.internal.ss.authz.settings.applied.marker does not exist
62200 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
62201 [main] INFO  o.a.h.h.m.ObjectStore - ObjectStore, initialize called
62244 [main] WARN  o.a.h.h.c.HiveConf - HiveConf of name hive.internal.ss.authz.settings.applied.marker does not exist
62246 [main] INFO  o.a.h.h.m.MetaStoreDirectSql - Using direct SQL, underlying DB is DERBY
62246 [main] INFO  o.a.h.h.m.ObjectStore - Initialized ObjectStore
62247 [main] WARN  o.a.h.h.m.ObjectStore - Failed to get database testdb, returning NoSuchObjectException
62247 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core testdb
62247 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core preEvent testdb
62247 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core filesystem testdb
62247 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core rdbms testdb
62256 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core rdbms committed testdb
62257 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core listeners testdb
62257 [main] INFO  o.a.h.h.m.HiveMetaStore - create_database_core listeners done testdb
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=runTasks start=1511881494583 end=1511881494687 duration=104 from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.Driver - Resetting the caller context to 
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.execute start=1511881494581 end=1511881494687 duration=106 from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.Driver - OK
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=releaseLocks start=1511881494687 end=1511881494687 duration=0 from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.run start=1511881494578 end=1511881494687 duration=109 from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
62257 [main] INFO  o.a.h.h.q.Driver - We are setting the hadoop caller context from  to nobody_20171128150454_8b6fa569-5a71-41c5-b207-df78c7b738c2
62257 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
62258 [main] INFO  h.q.p.ParseDriver - Parsing command: use testdb
62258 [main] INFO  h.q.p.ParseDriver - Parse Completed
62258 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=parse start=1511881494687 end=1511881494688 duration=1 from=org.apache.hadoop.hive.ql.Driver>
62258 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
62258 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_database: testdb
62258 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_database: testdb	
62259 [main] INFO  o.a.h.h.q.Driver - Semantic Analysis Completed
62259 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=semanticAnalyze start=1511881494688 end=1511881494689 duration=1 from=org.apache.hadoop.hive.ql.Driver>
62259 [main] INFO  o.a.h.h.q.Driver - Returning Hive schema: Schema(fieldSchemas:null, properties:null)
62259 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=compile start=1511881494687 end=1511881494689 duration=2 from=org.apache.hadoop.hive.ql.Driver>
62259 [main] INFO  o.a.h.h.q.Driver - We are resetting the hadoop caller context to 
62259 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=acquireReadWriteLocks from=org.apache.hadoop.hive.ql.Driver>
62259 [main] INFO  o.a.h.h.q.l.DbTxnManager - Setting lock request transaction to txnid:0 for queryId=nobody_20171128150454_8b6fa569-5a71-41c5-b207-df78c7b738c2
62259 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=acquireReadWriteLocks start=1511881494689 end=1511881494689 duration=0 from=org.apache.hadoop.hive.ql.Driver>
62259 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
62259 [main] INFO  o.a.h.h.q.Driver - Setting caller context to query id nobody_20171128150454_8b6fa569-5a71-41c5-b207-df78c7b738c2
62259 [main] INFO  o.a.h.h.q.Driver - Starting command(queryId=nobody_20171128150454_8b6fa569-5a71-41c5-b207-df78c7b738c2): create database IF NOT EXISTS testdb location 'raw:///tmp/junit8935893841909704896/testdb.db'
62259 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
62259 [main] INFO  o.a.h.h.q.Driver - Starting task [Stage-0:DDL] in serial mode
62260 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_database: testdb
62260 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_database: testdb	
62260 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_database: testdb
62260 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_database: testdb	
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=runTasks start=1511881494689 end=1511881494691 duration=2 from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.Driver - Resetting the caller context to 
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.execute start=1511881494689 end=1511881494691 duration=2 from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.Driver - OK
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=releaseLocks start=1511881494691 end=1511881494691 duration=0 from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.run start=1511881494687 end=1511881494691 duration=4 from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  o.a.h.h.q.Driver - We are setting the hadoop caller context from  to nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3
62261 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
62261 [main] INFO  h.q.p.ParseDriver - Parsing command: create table test_table ( id int,msg string ) partitioned by (city string,state string ) clustered by ( id ) into 10 buckets  stored as orc  location 'raw:///tmp/junit8935893841909704896/testdb.db/test_table' TBLPROPERTIES ('transactional'='true')
62262 [main] INFO  h.q.p.ParseDriver - Parse Completed
62262 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=parse start=1511881494691 end=1511881494692 duration=1 from=org.apache.hadoop.hive.ql.Driver>
62262 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
62262 [main] INFO  o.a.h.h.q.p.CalcitePlanner - Starting Semantic Analysis
62262 [main] INFO  o.a.h.h.q.p.CalcitePlanner - Creating table testdb.test_table position=13
62263 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_database: testdb
62263 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_database: testdb	
62263 [main] INFO  o.a.h.h.q.Driver - Semantic Analysis Completed
62263 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=semanticAnalyze start=1511881494692 end=1511881494693 duration=1 from=org.apache.hadoop.hive.ql.Driver>
62263 [main] INFO  o.a.h.h.q.Driver - Returning Hive schema: Schema(fieldSchemas:null, properties:null)
62263 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=compile start=1511881494691 end=1511881494693 duration=2 from=org.apache.hadoop.hive.ql.Driver>
62264 [main] INFO  o.a.h.h.q.Driver - We are resetting the hadoop caller context to 
62264 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=acquireReadWriteLocks from=org.apache.hadoop.hive.ql.Driver>
62264 [main] INFO  o.a.h.h.q.l.DbTxnManager - Setting lock request transaction to txnid:0 for queryId=nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3
62264 [main] INFO  o.a.h.h.q.l.DbLockManager - Requesting: queryId=nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3 LockRequest(component:[LockComponent(type:SHARED_READ, level:DB, dbname:testdb, operationType:NO_TXN, isDynamicPartitionWrite:false)], txnid:0, user:nobody, hostname:ctr-e134-1499953498516-345859-01-000003.hwx.site, agentInfo:nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3)
62283 [main] INFO  o.a.h.h.q.l.DbLockManager - Response to queryId=nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3 LockResponse(lockid:1, state:ACQUIRED)
62283 [main] INFO  o.a.h.h.q.l.DbTxnManager - Started heartbeat with delay/interval = 150000/150000 MILLISECONDS for query: nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3
62283 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=acquireReadWriteLocks start=1511881494694 end=1511881494713 duration=19 from=org.apache.hadoop.hive.ql.Driver>
62283 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
62283 [main] INFO  o.a.h.h.q.Driver - Setting caller context to query id nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3
62283 [main] INFO  o.a.h.h.q.Driver - Starting command(queryId=nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3): create database IF NOT EXISTS testdb location 'raw:///tmp/junit8935893841909704896/testdb.db'
62283 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
62283 [main] INFO  o.a.h.h.q.Driver - Starting task [Stage-0:DDL] in serial mode
62285 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: create_table: Table(tableName:test_table, dbName:testdb, owner:nobody, createTime:1511881494, lastAccessTime:0, retention:0, sd:StorageDescriptor(cols:[FieldSchema(name:id, type:int, comment:null), FieldSchema(name:msg, type:string, comment:null)], location:raw:/tmp/junit8935893841909704896/testdb.db/test_table, inputFormat:org.apache.hadoop.hive.ql.io.orc.OrcInputFormat, outputFormat:org.apache.hadoop.hive.ql.io.orc.OrcOutputFormat, compressed:false, numBuckets:10, serdeInfo:SerDeInfo(name:null, serializationLib:org.apache.hadoop.hive.ql.io.orc.OrcSerde, parameters:{serialization.format=1}), bucketCols:[id], sortCols:[], parameters:{}, skewedInfo:SkewedInfo(skewedColNames:[], skewedColValues:[], skewedColValueLocationMaps:{}), storedAsSubDirectories:false), partitionKeys:[FieldSchema(name:city, type:string, comment:null), FieldSchema(name:state, type:string, comment:null)], parameters:{transactional=true}, viewOriginalText:null, viewExpandedText:null, tableType:MANAGED_TABLE, privileges:PrincipalPrivilegeSet(userPrivileges:{nobody=[PrivilegeGrantInfo(privilege:INSERT, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true), PrivilegeGrantInfo(privilege:SELECT, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true), PrivilegeGrantInfo(privilege:UPDATE, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true), PrivilegeGrantInfo(privilege:DELETE, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true)]}, groupPrivileges:null, rolePrivileges:null), temporary:false)
62285 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=create_table: Table(tableName:test_table, dbName:testdb, owner:nobody, createTime:1511881494, lastAccessTime:0, retention:0, sd:StorageDescriptor(cols:[FieldSchema(name:id, type:int, comment:null), FieldSchema(name:msg, type:string, comment:null)], location:raw:/tmp/junit8935893841909704896/testdb.db/test_table, inputFormat:org.apache.hadoop.hive.ql.io.orc.OrcInputFormat, outputFormat:org.apache.hadoop.hive.ql.io.orc.OrcOutputFormat, compressed:false, numBuckets:10, serdeInfo:SerDeInfo(name:null, serializationLib:org.apache.hadoop.hive.ql.io.orc.OrcSerde, parameters:{serialization.format=1}), bucketCols:[id], sortCols:[], parameters:{}, skewedInfo:SkewedInfo(skewedColNames:[], skewedColValues:[], skewedColValueLocationMaps:{}), storedAsSubDirectories:false), partitionKeys:[FieldSchema(name:city, type:string, comment:null), FieldSchema(name:state, type:string, comment:null)], parameters:{transactional=true}, viewOriginalText:null, viewExpandedText:null, tableType:MANAGED_TABLE, privileges:PrincipalPrivilegeSet(userPrivileges:{nobody=[PrivilegeGrantInfo(privilege:INSERT, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true), PrivilegeGrantInfo(privilege:SELECT, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true), PrivilegeGrantInfo(privilege:UPDATE, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true), PrivilegeGrantInfo(privilege:DELETE, createTime:-1, grantor:nobody, grantorType:USER, grantOption:true)]}, groupPrivileges:null, rolePrivileges:null), temporary:false)	
62285 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core testdb.test_table
62285 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core preEvent testdb.test_table
62285 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core rdbms checks testdb.test_table
62286 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core filesystem testdb.test_table
62286 [main] WARN  o.a.h.h.m.HiveMetaStore - Location: raw:/tmp/junit8935893841909704896/testdb.db/test_table specified for non-external table:test_table
62286 [main] INFO  o.a.h.h.c.FileUtils - Creating directory if it doesn't exist: raw:/tmp/junit8935893841909704896/testdb.db/test_table
62288 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core stats testdb.test_table
62288 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core rdbms create testdb.test_table
62324 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core rdbms committed testdb.test_table
62324 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core rdbms listeners testdb.test_table
62324 [main] INFO  o.a.h.h.m.HiveMetaStore - create_table_core rdbms listeners done testdb.test_table
62324 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=runTasks start=1511881494713 end=1511881494754 duration=41 from=org.apache.hadoop.hive.ql.Driver>
62324 [main] INFO  o.a.h.h.q.Driver - Resetting the caller context to 
62324 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.execute start=1511881494713 end=1511881494754 duration=41 from=org.apache.hadoop.hive.ql.Driver>
62324 [main] INFO  o.a.h.h.q.Driver - OK
62324 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
62324 [main] INFO  o.a.h.h.q.l.DbTxnManager - Stopped heartbeat for query: nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3
62324 [main] INFO  o.a.h.h.q.l.DbLockManager - releaseLocks: [lockid:1 queryId=nobody_20171128150454_f8e917c9-4cbc-4512-b93a-65db6c890fa3 txnid:0]
62328 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=releaseLocks start=1511881494754 end=1511881494758 duration=4 from=org.apache.hadoop.hive.ql.Driver>
62328 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.run start=1511881494691 end=1511881494758 duration=67 from=org.apache.hadoop.hive.ql.Driver>
62328 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
62329 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
62329 [main] INFO  o.a.h.h.q.Driver - We are setting the hadoop caller context from  to nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73
62329 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
62329 [main] INFO  h.q.p.ParseDriver - Parsing command: alter table test_table add partition ( city = 'sunnyvale',state = 'ca' )
62329 [main] INFO  h.q.p.ParseDriver - Parse Completed
62329 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=parse start=1511881494759 end=1511881494759 duration=0 from=org.apache.hadoop.hive.ql.Driver>
62329 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
62330 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_table : db=testdb tbl=test_table
62330 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_table : db=testdb tbl=test_table	
62374 [main] INFO  o.a.h.h.q.Driver - Semantic Analysis Completed
62374 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=semanticAnalyze start=1511881494759 end=1511881494804 duration=45 from=org.apache.hadoop.hive.ql.Driver>
62374 [main] INFO  o.a.h.h.q.Driver - Returning Hive schema: Schema(fieldSchemas:null, properties:null)
62374 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=compile start=1511881494759 end=1511881494804 duration=45 from=org.apache.hadoop.hive.ql.Driver>
62374 [main] INFO  o.a.h.h.q.Driver - We are resetting the hadoop caller context to 
62374 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=acquireReadWriteLocks from=org.apache.hadoop.hive.ql.Driver>
62374 [main] INFO  o.a.h.h.q.l.DbTxnManager - Setting lock request transaction to txnid:0 for queryId=nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73
62374 [main] INFO  o.a.h.h.q.l.DbLockManager - Requesting: queryId=nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73 LockRequest(component:[LockComponent(type:SHARED_READ, level:TABLE, dbname:testdb, tablename:test_table, operationType:NO_TXN, isAcid:true, isDynamicPartitionWrite:false)], txnid:0, user:nobody, hostname:ctr-e134-1499953498516-345859-01-000003.hwx.site, agentInfo:nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73)
62386 [main] INFO  o.a.h.h.q.l.DbLockManager - Response to queryId=nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73 LockResponse(lockid:2, state:ACQUIRED)
62386 [main] INFO  o.a.h.h.q.l.DbTxnManager - Started heartbeat with delay/interval = 150000/150000 MILLISECONDS for query: nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73
62386 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=acquireReadWriteLocks start=1511881494804 end=1511881494816 duration=12 from=org.apache.hadoop.hive.ql.Driver>
62386 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
62386 [main] INFO  o.a.h.h.q.Driver - Setting caller context to query id nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73
62386 [main] INFO  o.a.h.h.q.Driver - Starting command(queryId=nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73): create database IF NOT EXISTS testdb location 'raw:///tmp/junit8935893841909704896/testdb.db'
62386 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
62387 [main] INFO  o.a.h.h.q.Driver - Starting task [Stage-0:DDL] in serial mode
62387 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: get_table : db=testdb tbl=test_table
62387 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=get_table : db=testdb tbl=test_table	
62393 [main] INFO  o.a.h.h.m.HiveMetaStore - 0: add_partitions
62393 [main] INFO  o.a.h.h.m.H.audit - ugi=nobody	ip=unknown-ip-addr	cmd=add_partitions	
62404 [HMSHandler #3] INFO  o.a.h.h.c.FileUtils - Creating directory if it doesn't exist: raw:/tmp/junit8935893841909704896/testdb.db/test_table/city=sunnyvale/state=ca
62422 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=runTasks start=1511881494816 end=1511881494852 duration=36 from=org.apache.hadoop.hive.ql.Driver>
62422 [main] INFO  o.a.h.h.q.Driver - Resetting the caller context to 
62422 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.execute start=1511881494816 end=1511881494852 duration=36 from=org.apache.hadoop.hive.ql.Driver>
62422 [main] INFO  o.a.h.h.q.Driver - OK
62422 [main] INFO  o.a.h.h.q.l.PerfLogger - <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
62422 [main] INFO  o.a.h.h.q.l.DbTxnManager - Stopped heartbeat for query: nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73
62422 [main] INFO  o.a.h.h.q.l.DbLockManager - releaseLocks: [lockid:2 queryId=nobody_20171128150454_ae26eba9-11ee-41a6-9632-4b64134ecb73 txnid:0]
62426 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=releaseLocks start=1511881494852 end=1511881494856 duration=4 from=org.apache.hadoop.hive.ql.Driver>
62426 [main] INFO  o.a.h.h.q.l.PerfLogger - </PERFLOG method=Driver.run start=1511881494758 end=1511881494856 duration=98 from=org.apache.hadoop.hive.ql.Driver>
Standard Error

OK
OK
OK
OK

Attachments

Issue Links

links to

GitHub Pull Request #2555

Activity

People

Assignee:: Jungtaek Lim

Reporter:: Yesha Vora

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 01/Dec/17 20:43

Updated:: 13/Feb/18 08:53

Resolved:: 13/Feb/18 08:53

Time Tracking

Estimated:

Not Specified

Remaining:

Logged:

0.5h