You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@storm.apache.org by "Jungtaek Lim (JIRA)" <ji...@apache.org> on 2018/02/12 08:51:00 UTC

[jira] [Commented] (STORM-2841) testNoAcksIfFlushFails UT fails with NullPointerException

    [ https://issues.apache.org/jira/browse/STORM-2841?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16360448#comment-16360448 ] 

Jungtaek Lim commented on STORM-2841:
-------------------------------------

This is actually super odd, because it shouldn't call the real method while mocking spy object partially but it is being called.

We could avoid NPE via calling prepare() earlier, but if the error indicates that the mocking is not working in that case, the test will fail anyway.

Maybe we can just try out replacing partial mock with extending class, since without mocking that method there's no need to spy the class.

> testNoAcksIfFlushFails UT fails with NullPointerException
> ---------------------------------------------------------
>
>                 Key: STORM-2841
>                 URL: https://issues.apache.org/jira/browse/STORM-2841
>             Project: Apache Storm
>          Issue Type: Test
>            Reporter: Yesha Vora
>            Priority: Major
>
> testNoAcksIfFlushFails UT fails with NPE
> {code}
> 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){code}
> {code}
> 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{code}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)