a2s6v3Yu

1    > select * from wikiticker_kafka;
22016-10-24T04:11:35,415 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Acquired the compile lock.
32016-10-24T04:11:35,418 DEBUG [main] conf.VariableSubstitution: Substitution is on: select * from wikiticker_kafka
42016-10-24T04:11:35,441  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Compiling command(queryId=vagrant_20161024041135_87e818a1-e564-46c7-a50b-a0e14d1c9513): select * from wikiticker_kafka
52016-10-24T04:11:35,453 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.ParseDriver: Parsing command: select * from wikiticker_kafka
62016-10-24T04:11:35,730 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.ParseDriver: Parse Completed
72016-10-24T04:11:35,852  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
82016-10-24T04:11:35,874 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.connectionPoolingType value null from  jpox.properties with BONECP
92016-10-24T04:11:35,874 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionDriverName value null from  jpox.properties with com.mysql.jdbc.Driver
102016-10-24T04:11:35,874 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.autoStartMechanismMode value null from  jpox.properties with ignored
112016-10-24T04:11:35,874 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.schema.autoCreateAll value null from  jpox.properties with false
122016-10-24T04:11:35,874 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.schema.validateColumns value null from  jpox.properties with false
132016-10-24T04:11:35,875 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.schema.validateTables value null from  jpox.properties with false
142016-10-24T04:11:35,875 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.autoCreateSchema value null from  jpox.properties with false
152016-10-24T04:11:35,875 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.rdbms.useLegacyNativeValueStrategy value null from  jpox.properties with true
162016-10-24T04:11:35,875 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding hive.metastore.integral.jdo.pushdown value null from  jpox.properties with false
172016-10-24T04:11:35,876 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.PersistenceManagerFactoryClass value null from  jpox.properties with org.datanucleus.api.jdo.JDOPersistenceManagerFactory
182016-10-24T04:11:35,876 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.cache.level2 value null from  jpox.properties with false
192016-10-24T04:11:35,876 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionUserName value null from  jpox.properties with hive
202016-10-24T04:11:35,877 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.cache.level2.type value null from  jpox.properties with none
212016-10-24T04:11:35,877 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.plugin.pluginRegistryBundleCheck value null from  jpox.properties with LOG
222016-10-24T04:11:35,877 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.rdbms.initializeColumnInfo value null from  jpox.properties with NONE
232016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.option.NonTransactionalRead value null from  jpox.properties with true
242016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.identifierFactory value null from  jpox.properties with datanucleus1
252016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionURL value null from  jpox.properties with jdbc:mysql://druid.example.com:3306/hive?createDatabaseIfNotExist=true
262016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.option.DetachAllOnCommit value null from  jpox.properties with true
272016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.storeManagerType value null from  jpox.properties with rdbms
282016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.autoStartMechanism value null from  jpox.properties with SchemaTable
292016-10-24T04:11:35,878 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.transactionIsolation value null from  jpox.properties with read-committed
302016-10-24T04:11:35,879 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding datanucleus.schema.validateConstraints value null from  jpox.properties with false
312016-10-24T04:11:35,879 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Overriding javax.jdo.option.Multithreaded value null from  jpox.properties with true
322016-10-24T04:11:35,880 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.schema.autoCreateAll = false
332016-10-24T04:11:35,880 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.schema.validateTables = false
342016-10-24T04:11:35,880 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.rdbms.useLegacyNativeValueStrategy = true
352016-10-24T04:11:35,880 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.schema.validateColumns = false
362016-10-24T04:11:35,881 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: hive.metastore.integral.jdo.pushdown = false
372016-10-24T04:11:35,881 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.autoStartMechanismMode = ignored
382016-10-24T04:11:35,881 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.rdbms.initializeColumnInfo = NONE
392016-10-24T04:11:35,881 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.option.Multithreaded = true
402016-10-24T04:11:35,881 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.identifierFactory = datanucleus1
412016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.transactionIsolation = read-committed
422016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.autoStartMechanism = SchemaTable
432016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.option.ConnectionURL = jdbc:mysql://druid.example.com:3306/hive?createDatabaseIfNotExist=true
442016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.option.DetachAllOnCommit = true
452016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.option.NonTransactionalRead = true
462016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.schema.validateConstraints = false
472016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.option.ConnectionDriverName = com.mysql.jdbc.Driver
482016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.option.ConnectionUserName = hive
492016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.cache.level2 = false
502016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.plugin.pluginRegistryBundleCheck = LOG
512016-10-24T04:11:35,882 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.cache.level2.type = none
522016-10-24T04:11:35,883 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: javax.jdo.PersistenceManagerFactoryClass = org.datanucleus.api.jdo.JDOPersistenceManagerFactory
532016-10-24T04:11:35,883 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.autoCreateSchema = false
542016-10-24T04:11:35,883 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.storeManagerType = rdbms
552016-10-24T04:11:35,883 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: datanucleus.connectionPoolingType = BONECP
562016-10-24T04:11:35,883  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: ObjectStore, initialize called
572016-10-24T04:11:36,247 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] bonecp.BoneCPDataSource: JDBC URL = jdbc:mysql://druid.example.com:3306/hive?createDatabaseIfNotExist=true, Username = hive, partitions = 1, max (per partition) = 10, min (per partition) = 0, idle max age = 60 min, idle test period = 240 min, strategy = DEFAULT
582016-10-24T04:11:37,420  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,Database,Type,FieldSchema,Order"
592016-10-24T04:11:37,516 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] bonecp.BoneCPDataSource: JDBC URL = jdbc:mysql://druid.example.com:3306/hive?createDatabaseIfNotExist=true, Username = hive, partitions = 1, max (per partition) = 10, min (per partition) = 0, idle max age = 60 min, idle test period = 240 min, strategy = DEFAULT
602016-10-24T04:11:37,563 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.MetaStoreDirectSql: Direct SQL query in 0.173444ms + 0.046141ms, the query is [SET @@session.sql_mode=ANSI_QUOTES]
612016-10-24T04:11:37,574  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.MetaStoreDirectSql: Using direct SQL, underlying DB is MYSQL
622016-10-24T04:11:37,578 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@82a85f2, with PersistenceManager: org.datanucleus.api.jdo.JDOPersistenceManager@114a56f6 created in the thread with id: 1
632016-10-24T04:11:37,578  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Initialized ObjectStore
642016-10-24T04:11:37,631 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
65	org.apache.hadoop.hive.metastore.ObjectStore.getMSchemaVersion(ObjectStore.java:7912)
662016-10-24T04:11:37,650 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
67	org.apache.hadoop.hive.metastore.ObjectStore.getMSchemaVersion(ObjectStore.java:7925)
682016-10-24T04:11:37,654 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Found expected HMS version of 2.1.0
692016-10-24T04:11:37,664 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
70	org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.start(ObjectStore.java:2813)
712016-10-24T04:11:37,666 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.MetaStoreDirectSql: Direct SQL query in 0.142922ms + 0.01594ms, the query is [SET @@session.sql_mode=ANSI_QUOTES]
722016-10-24T04:11:37,674 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.MetaStoreDirectSql: getDatabase: directsql returning db default locn[hdfs://druid.example.com:8020/apps/hive/warehouse] desc [Default Hive database] owner [public] ownertype [ROLE]
732016-10-24T04:11:37,675 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
74	org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.commit(ObjectStore.java:2906)
752016-10-24T04:11:37,675 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: db details for db default retrieved using SQL in 11.140442ms
762016-10-24T04:11:37,676 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
77	org.apache.hadoop.hive.metastore.ObjectStore.addRole(ObjectStore.java:3937)
782016-10-24T04:11:37,676 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 2, isActive = true at:
79	org.apache.hadoop.hive.metastore.ObjectStore.getMRole(ObjectStore.java:4294)
802016-10-24T04:11:37,680 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 1, isactive true at:
81	org.apache.hadoop.hive.metastore.ObjectStore.getMRole(ObjectStore.java:4300)
822016-10-24T04:11:37,682 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Rollback transaction, isActive: true at:
83	org.apache.hadoop.hive.metastore.ObjectStore.addRole(ObjectStore.java:3949)
842016-10-24T04:11:37,683 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: admin role already exists
85org.apache.hadoop.hive.metastore.api.InvalidObjectException: Role admin already exists.
86	at org.apache.hadoop.hive.metastore.ObjectStore.addRole(ObjectStore.java:3940) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
87	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_111]
88	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_111]
89	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_111]
90	at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_111]
91	at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:101) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
92	at com.sun.proxy.$Proxy52.addRole(Unknown Source) ~[?:?]
93	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultRoles_core(HiveMetaStore.java:666) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
94	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultRoles(HiveMetaStore.java:655) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
95	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:421) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
96	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
97	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:84) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
98	at org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6523) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
99	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:241) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
100	at org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient.<init>(SessionHiveMetaStoreClient.java:70) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
101	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.7.0_111]
102	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[?:1.7.0_111]
103	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.7.0_111]
104	at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[?:1.7.0_111]
105	at org.apache.hadoop.hive.metastore.MetaStoreUtils.newInstance(MetaStoreUtils.java:1659) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
106	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.<init>(RetryingMetaStoreClient.java:81) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
107	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:131) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
108	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:102) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
109	at org.apache.hadoop.hive.ql.metadata.Hive.createMetaStoreClient(Hive.java:3495) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
110	at org.apache.hadoop.hive.ql.metadata.Hive.getMSC(Hive.java:3547) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
111	at org.apache.hadoop.hive.ql.metadata.Hive.getMSC(Hive.java:3527) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
112	at org.apache.hadoop.hive.ql.metadata.Hive.getAllFunctions(Hive.java:3781) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
113	at org.apache.hadoop.hive.ql.metadata.Hive.reloadFunctions(Hive.java:243) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
114	at org.apache.hadoop.hive.ql.metadata.Hive.registerAllFunctionsOnce(Hive.java:226) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
115	at org.apache.hadoop.hive.ql.metadata.Hive.<init>(Hive.java:383) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
116	at org.apache.hadoop.hive.ql.metadata.Hive.create(Hive.java:327) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
117	at org.apache.hadoop.hive.ql.metadata.Hive.getInternal(Hive.java:307) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
118	at org.apache.hadoop.hive.ql.metadata.Hive.get(Hive.java:283) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
119	at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.createHiveDB(BaseSemanticAnalyzer.java:229) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
120	at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.<init>(BaseSemanticAnalyzer.java:208) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
121	at org.apache.hadoop.hive.ql.parse.SemanticAnalyzer.<init>(SemanticAnalyzer.java:353) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
122	at org.apache.hadoop.hive.ql.parse.CalcitePlanner.<init>(CalcitePlanner.java:251) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
123	at org.apache.hadoop.hive.ql.parse.SemanticAnalyzerFactory.get(SemanticAnalyzerFactory.java:306) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
124	at org.apache.hadoop.hive.ql.Driver.compile(Driver.java:482) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
125	at org.apache.hadoop.hive.ql.Driver.compileInternal(Driver.java:1299) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
126	at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1439) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
127	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1219) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
128	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1209) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
129	at org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:233) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
130	at org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:184) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
131	at org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:400) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
132	at org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:777) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
133	at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:715) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
134	at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:642) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
135	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_111]
136	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_111]
137	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_111]
138	at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_111]
139	at org.apache.hadoop.util.RunJar.run(RunJar.java:233) ~[hadoop-common-2.7.3.2.6.0.0-80.jar:?]
140	at org.apache.hadoop.util.RunJar.main(RunJar.java:148) ~[hadoop-common-2.7.3.2.6.0.0-80.jar:?]
1412016-10-24T04:11:37,683  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: Added admin role in metastore
1422016-10-24T04:11:37,684 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
143	org.apache.hadoop.hive.metastore.ObjectStore.addRole(ObjectStore.java:3937)
1442016-10-24T04:11:37,684 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 2, isActive = true at:
145	org.apache.hadoop.hive.metastore.ObjectStore.getMRole(ObjectStore.java:4294)
1462016-10-24T04:11:37,685 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 1, isactive true at:
147	org.apache.hadoop.hive.metastore.ObjectStore.getMRole(ObjectStore.java:4300)
1482016-10-24T04:11:37,685 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Rollback transaction, isActive: true at:
149	org.apache.hadoop.hive.metastore.ObjectStore.addRole(ObjectStore.java:3949)
1502016-10-24T04:11:37,686 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: public role already exists
151org.apache.hadoop.hive.metastore.api.InvalidObjectException: Role public already exists.
152	at org.apache.hadoop.hive.metastore.ObjectStore.addRole(ObjectStore.java:3940) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
153	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_111]
154	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_111]
155	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_111]
156	at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_111]
157	at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:101) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
158	at com.sun.proxy.$Proxy52.addRole(Unknown Source) ~[?:?]
159	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultRoles_core(HiveMetaStore.java:675) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
160	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultRoles(HiveMetaStore.java:655) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
161	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:421) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
162	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
163	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:84) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
164	at org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6523) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
165	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:241) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
166	at org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient.<init>(SessionHiveMetaStoreClient.java:70) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
167	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.7.0_111]
168	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[?:1.7.0_111]
169	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.7.0_111]
170	at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[?:1.7.0_111]
171	at org.apache.hadoop.hive.metastore.MetaStoreUtils.newInstance(MetaStoreUtils.java:1659) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
172	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.<init>(RetryingMetaStoreClient.java:81) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
173	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:131) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
174	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:102) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
175	at org.apache.hadoop.hive.ql.metadata.Hive.createMetaStoreClient(Hive.java:3495) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
176	at org.apache.hadoop.hive.ql.metadata.Hive.getMSC(Hive.java:3547) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
177	at org.apache.hadoop.hive.ql.metadata.Hive.getMSC(Hive.java:3527) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
178	at org.apache.hadoop.hive.ql.metadata.Hive.getAllFunctions(Hive.java:3781) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
179	at org.apache.hadoop.hive.ql.metadata.Hive.reloadFunctions(Hive.java:243) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
180	at org.apache.hadoop.hive.ql.metadata.Hive.registerAllFunctionsOnce(Hive.java:226) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
181	at org.apache.hadoop.hive.ql.metadata.Hive.<init>(Hive.java:383) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
182	at org.apache.hadoop.hive.ql.metadata.Hive.create(Hive.java:327) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
183	at org.apache.hadoop.hive.ql.metadata.Hive.getInternal(Hive.java:307) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
184	at org.apache.hadoop.hive.ql.metadata.Hive.get(Hive.java:283) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
185	at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.createHiveDB(BaseSemanticAnalyzer.java:229) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
186	at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.<init>(BaseSemanticAnalyzer.java:208) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
187	at org.apache.hadoop.hive.ql.parse.SemanticAnalyzer.<init>(SemanticAnalyzer.java:353) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
188	at org.apache.hadoop.hive.ql.parse.CalcitePlanner.<init>(CalcitePlanner.java:251) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
189	at org.apache.hadoop.hive.ql.parse.SemanticAnalyzerFactory.get(SemanticAnalyzerFactory.java:306) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
190	at org.apache.hadoop.hive.ql.Driver.compile(Driver.java:482) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
191	at org.apache.hadoop.hive.ql.Driver.compileInternal(Driver.java:1299) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
192	at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1439) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
193	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1219) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
194	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1209) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
195	at org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:233) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
196	at org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:184) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
197	at org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:400) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
198	at org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:777) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
199	at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:715) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
200	at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:642) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
201	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_111]
202	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_111]
203	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_111]
204	at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_111]
205	at org.apache.hadoop.util.RunJar.run(RunJar.java:233) ~[hadoop-common-2.7.3.2.6.0.0-80.jar:?]
206	at org.apache.hadoop.util.RunJar.main(RunJar.java:148) ~[hadoop-common-2.7.3.2.6.0.0-80.jar:?]
2072016-10-24T04:11:37,686  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: Added public role in metastore
2082016-10-24T04:11:37,694 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
209	org.apache.hadoop.hive.metastore.ObjectStore.grantPrivileges(ObjectStore.java:4687)
2102016-10-24T04:11:37,695 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 2, isActive = true at:
211	org.apache.hadoop.hive.metastore.ObjectStore.getMRole(ObjectStore.java:4294)
2122016-10-24T04:11:37,696 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 1, isactive true at:
213	org.apache.hadoop.hive.metastore.ObjectStore.getMRole(ObjectStore.java:4300)
2142016-10-24T04:11:37,696 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 2, isActive = true at:
215	org.apache.hadoop.hive.metastore.ObjectStore.listPrincipalMGlobalGrants(ObjectStore.java:5203)
2162016-10-24T04:11:37,700 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 1, isactive true at:
217	org.apache.hadoop.hive.metastore.ObjectStore.listPrincipalMGlobalGrants(ObjectStore.java:5211)
2182016-10-24T04:11:37,700 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Rollback transaction, isActive: true at:
219	org.apache.hadoop.hive.metastore.ObjectStore.grantPrivileges(ObjectStore.java:4890)
2202016-10-24T04:11:37,704 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: Failed while granting global privs to admin
221org.apache.hadoop.hive.metastore.api.InvalidObjectException: All is already granted by admin
222	at org.apache.hadoop.hive.metastore.ObjectStore.grantPrivileges(ObjectStore.java:4723) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
223	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_111]
224	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_111]
225	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_111]
226	at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_111]
227	at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:101) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
228	at com.sun.proxy.$Proxy52.grantPrivileges(Unknown Source) ~[?:?]
229	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultRoles_core(HiveMetaStore.java:689) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
230	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultRoles(HiveMetaStore.java:655) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
231	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:421) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
232	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
233	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:84) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
234	at org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6523) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
235	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:241) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
236	at org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient.<init>(SessionHiveMetaStoreClient.java:70) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
237	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.7.0_111]
238	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[?:1.7.0_111]
239	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.7.0_111]
240	at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[?:1.7.0_111]
241	at org.apache.hadoop.hive.metastore.MetaStoreUtils.newInstance(MetaStoreUtils.java:1659) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
242	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.<init>(RetryingMetaStoreClient.java:81) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
243	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:131) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
244	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:102) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
245	at org.apache.hadoop.hive.ql.metadata.Hive.createMetaStoreClient(Hive.java:3495) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
246	at org.apache.hadoop.hive.ql.metadata.Hive.getMSC(Hive.java:3547) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
247	at org.apache.hadoop.hive.ql.metadata.Hive.getMSC(Hive.java:3527) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
248	at org.apache.hadoop.hive.ql.metadata.Hive.getAllFunctions(Hive.java:3781) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
249	at org.apache.hadoop.hive.ql.metadata.Hive.reloadFunctions(Hive.java:243) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
250	at org.apache.hadoop.hive.ql.metadata.Hive.registerAllFunctionsOnce(Hive.java:226) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
251	at org.apache.hadoop.hive.ql.metadata.Hive.<init>(Hive.java:383) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
252	at org.apache.hadoop.hive.ql.metadata.Hive.create(Hive.java:327) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
253	at org.apache.hadoop.hive.ql.metadata.Hive.getInternal(Hive.java:307) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
254	at org.apache.hadoop.hive.ql.metadata.Hive.get(Hive.java:283) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
255	at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.createHiveDB(BaseSemanticAnalyzer.java:229) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
256	at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.<init>(BaseSemanticAnalyzer.java:208) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
257	at org.apache.hadoop.hive.ql.parse.SemanticAnalyzer.<init>(SemanticAnalyzer.java:353) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
258	at org.apache.hadoop.hive.ql.parse.CalcitePlanner.<init>(CalcitePlanner.java:251) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
259	at org.apache.hadoop.hive.ql.parse.SemanticAnalyzerFactory.get(SemanticAnalyzerFactory.java:306) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
260	at org.apache.hadoop.hive.ql.Driver.compile(Driver.java:482) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
261	at org.apache.hadoop.hive.ql.Driver.compileInternal(Driver.java:1299) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
262	at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1439) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
263	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1219) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
264	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1209) ~[hive-exec-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
265	at org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:233) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
266	at org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:184) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
267	at org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:400) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
268	at org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:777) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
269	at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:715) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
270	at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:642) ~[hive-cli-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
271	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_111]
272	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_111]
273	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_111]
274	at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_111]
275	at org.apache.hadoop.util.RunJar.run(RunJar.java:233) ~[hadoop-common-2.7.3.2.6.0.0-80.jar:?]
276	at org.apache.hadoop.util.RunJar.main(RunJar.java:148) ~[hadoop-common-2.7.3.2.6.0.0-80.jar:?]
2772016-10-24T04:11:37,704  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: No user is added in admin role, since config is empty
2782016-10-24T04:11:37,825  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: 0: get_all_functions
2792016-10-24T04:11:37,825  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] HiveMetaStore.audit: ugi=vagrant	ip=unknown-ip-addr	cmd=get_all_functions
2802016-10-24T04:11:37,825 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
281	org.apache.hadoop.hive.metastore.ObjectStore.getAllFunctions(ObjectStore.java:8201)
2822016-10-24T04:11:37,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
283	org.apache.hadoop.hive.metastore.ObjectStore.getAllFunctions(ObjectStore.java:8205)
2842016-10-24T04:11:37,839  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Starting Semantic Analysis
2852016-10-24T04:11:37,853  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Completed phase 1 of Semantic Analysis
2862016-10-24T04:11:37,853  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Get metadata for source tables
2872016-10-24T04:11:37,853  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: 0: get_table : db=default tbl=wikiticker_kafka
2882016-10-24T04:11:37,853  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] HiveMetaStore.audit: ugi=vagrant	ip=unknown-ip-addr	cmd=get_table : db=default tbl=wikiticker_kafka
2892016-10-24T04:11:37,853 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
290	org.apache.hadoop.hive.metastore.ObjectStore.getTable(ObjectStore.java:1187)
2912016-10-24T04:11:37,854 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 2, isActive = true at:
292	org.apache.hadoop.hive.metastore.ObjectStore.getMTable(ObjectStore.java:1389)
2932016-10-24T04:11:37,891 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 1, isactive true at:
294	org.apache.hadoop.hive.metastore.ObjectStore.getMTable(ObjectStore.java:1403)
2952016-10-24T04:11:37,921 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
296	org.apache.hadoop.hive.metastore.ObjectStore.getTable(ObjectStore.java:1189)
2972016-10-24T04:11:37,949  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Get metadata for subqueries
2982016-10-24T04:11:37,966  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Get metadata for destination tables
2992016-10-24T04:11:37,969 ERROR [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] hdfs.KeyProviderCache: Could not find uri with key [dfs.encryption.key.provider.uri] to create a keyProvider !!
3002016-10-24T04:11:37,971 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #63
3012016-10-24T04:11:37,972 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #63
3022016-10-24T04:11:37,973 DEBUG [main] ipc.ProtobufRpcEngine: Call: getEZForPath took 3ms
3032016-10-24T04:11:37,982 DEBUG [main] hdfs.DFSClient: /tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1: masked=rwx------
3042016-10-24T04:11:37,982 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #64
3052016-10-24T04:11:37,984 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #64
3062016-10-24T04:11:37,984 DEBUG [main] ipc.ProtobufRpcEngine: Call: mkdirs took 2ms
3072016-10-24T04:11:37,985 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #65
3082016-10-24T04:11:37,985 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #65
3092016-10-24T04:11:37,985 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
3102016-10-24T04:11:37,986  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Context: New scratch dir is hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1
3112016-10-24T04:11:37,989  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Completed getting MetaData in Semantic Analysis
3122016-10-24T04:11:38,431 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] hive.log: DDL: struct wikiticker_kafka { timestamp __time, float added, string channel, string comment, i64 count, float deleted, float delta, string diffurl, string flags, string isminor, string isnew, string isrobot, string isunpatrolled, string namespace, string page, string user, string user_unique}
3132016-10-24T04:11:38,733 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] starting
3142016-10-24T04:11:38,734  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] pool.ChannelResourceFactory: Generating: http://localhost:8082
3152016-10-24T04:11:38,811 DEBUG [HttpClient-Netty-Worker-0] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] messageReceived: DefaultHttpResponse(chunked: true)
316HTTP/1.1 200 OK
317Date: Mon, 24 Oct 2016 04:11:38 GMT
318Content-Type: application/x-jackson-smile
319X-Druid-Query-Id: 731f4f65-77f3-46fa-96ed-d600c8d88980
320X-Druid-Response-Context: {}
321Vary: Accept-Encoding, User-Agent
322Transfer-Encoding: chunked
323Server: Jetty(9.2.5.v20141112)
3242016-10-24T04:11:38,811 DEBUG [HttpClient-Netty-Worker-0] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] Got response: 200 OK
3252016-10-24T04:11:38,816 DEBUG [HttpClient-Netty-Worker-0] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] messageReceived: org.apache.hive.druid.org.jboss.netty.handler.codec.http.DefaultHttpChunk@5ab79af7
3262016-10-24T04:11:38,817 DEBUG [HttpClient-Netty-Worker-0] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] Got chunk: 674B, last=false
3272016-10-24T04:11:38,817 DEBUG [HttpClient-Netty-Worker-0] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] messageReceived: org.apache.hive.druid.org.jboss.netty.handler.codec.http.HttpChunk$1@4d271fc0
3282016-10-24T04:11:38,817 DEBUG [HttpClient-Netty-Worker-0] client.NettyHttpClient: [POST http://localhost:8082/druid/v2/] Got chunk: 0B, last=true
3292016-10-24T04:11:38,868  WARN [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] serde.DruidSerDeUtils: Transformation to STRING for unknown type HYPERUNIQUE
3302016-10-24T04:11:38,874 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] serde.DruidSerDe: DruidSerDe initialized with
331	 columns: [__time, added, channel, comment, count, deleted, delta, diffUrl, flags, isMinor, isNew, isRobot, isUnpatrolled, namespace, page, user, user_unique]
332	 types: [timestamp, float, string, string, bigint, float, float, string, string, string, string, string, string, string, string, string, string]
3332016-10-24T04:11:38,942 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created Plan for Query Block null
3342016-10-24T04:11:39,182 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] calcite.sql2rel: Plan after trimming unused fields
335HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
336  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
337
3382016-10-24T04:11:39,211 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#4:HiveProject.HIVE.[](input=HepRelVertex#3,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3392016-10-24T04:11:39,211 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3402016-10-24T04:11:39,215 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#7:HiveProject.HIVE.[](input=HepRelVertex#6,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3412016-10-24T04:11:39,215 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3422016-10-24T04:11:39,216 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#10:HiveProject.HIVE.[](input=HepRelVertex#9,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3432016-10-24T04:11:39,216 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3442016-10-24T04:11:39,217 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#13:HiveProject.HIVE.[](input=HepRelVertex#12,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3452016-10-24T04:11:39,218 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3462016-10-24T04:11:39,220 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#16:HiveProject.HIVE.[](input=HepRelVertex#15,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3472016-10-24T04:11:39,220 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3482016-10-24T04:11:39,237 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: call#0: Apply rule [ReduceExpressionsRule(Project)] to [rel#19:HiveProject.HIVE.[](input=HepRelVertex#18,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)]
3492016-10-24T04:11:39,261 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#19:HiveProject.HIVE.[](input=HepRelVertex#18,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3502016-10-24T04:11:39,262 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3512016-10-24T04:11:39,264 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#22:HiveProject.HIVE.[](input=HepRelVertex#21,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3522016-10-24T04:11:39,264 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3532016-10-24T04:11:39,265 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#25:HiveProject.HIVE.[](input=HepRelVertex#24,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)
3542016-10-24T04:11:39,265 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3552016-10-24T04:11:39,298 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] calcite.sql2rel: Plan after trimming unused fields
356HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
357  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
358
3592016-10-24T04:11:39,301 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: call#1: Apply rule [ProjectRemoveRule] to [rel#28:HiveProject.HIVE.[](input=HepRelVertex#27,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)]
3602016-10-24T04:11:39,301 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: call#1: Rule ProjectRemoveRule arguments [rel#28:HiveProject.HIVE.[](input=HepRelVertex#27,__time=$0,added=$1,channel=$2,comment=$3,count=$4,deleted=$5,delta=$6,diffurl=$7,flags=$8,isminor=$9,isnew=$10,isrobot=$11,isunpatrolled=$12,namespace=$13,page=$14,user=$15,user_unique=$16)] produced HepRelVertex#27
3612016-10-24T04:11:39,303 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3622016-10-24T04:11:39,304 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3632016-10-24T04:11:39,306 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3642016-10-24T04:11:39,312 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] plan.RelOptPlanner: For final plan, using rel#1:DruidQuery.HIVE.[](table=[default.wikiticker_kafka],intervals=[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z])
3652016-10-24T04:11:39,312 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: CBO Planning details:
366
3672016-10-24T04:11:39,312 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Original Plan:
368HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
369  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
370
3712016-10-24T04:11:39,313 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Plan After PPD, PartPruning, ColumnPruning:
372DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
373
3742016-10-24T04:11:39,360 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Plan After Join Reordering:
375DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]]): rowcount = 1.0, cumulative cost = {0}, id = 1
376
3772016-10-24T04:11:39,367 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] translator.PlanModifierForASTConv: Original plan for PlanModifier
378 DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
379
3802016-10-24T04:11:39,369 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] translator.PlanModifierForASTConv: Plan after top-level introduceDerivedTable
381 HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
382  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
383
3842016-10-24T04:11:39,370 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] translator.PlanModifierForASTConv: Plan after nested convertOpTree
385 HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
386  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
387
3882016-10-24T04:11:39,371 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] translator.PlanModifierForASTConv: Plan after propagating order
389 HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
390  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
391
3922016-10-24T04:11:39,374 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] translator.PlanModifierForASTConv: Plan after fixTopOBSchema
393 HiveProject(__time=[$0], added=[$1], channel=[$2], comment=[$3], count=[$4], deleted=[$5], delta=[$6], diffurl=[$7], flags=[$8], isminor=[$9], isnew=[$10], isrobot=[$11], isunpatrolled=[$12], namespace=[$13], page=[$14], user=[$15], user_unique=[$16])
394  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
395
3962016-10-24T04:11:39,374 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] translator.PlanModifierForASTConv: Final plan after modifier
397 HiveProject(wikiticker_kafka.__time=[$0], wikiticker_kafka.added=[$1], wikiticker_kafka.channel=[$2], wikiticker_kafka.comment=[$3], wikiticker_kafka.count=[$4], wikiticker_kafka.deleted=[$5], wikiticker_kafka.delta=[$6], wikiticker_kafka.diffurl=[$7], wikiticker_kafka.flags=[$8], wikiticker_kafka.isminor=[$9], wikiticker_kafka.isnew=[$10], wikiticker_kafka.isrobot=[$11], wikiticker_kafka.isunpatrolled=[$12], wikiticker_kafka.namespace=[$13], wikiticker_kafka.page=[$14], wikiticker_kafka.user=[$15], wikiticker_kafka.user_unique=[$16])
398  DruidQuery(table=[[default.wikiticker_kafka]], intervals=[[1900-01-01T00:00:00.000Z/3000-01-01T00:00:00.000Z]])
399
4002016-10-24T04:11:39,385  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Get metadata for source tables
4012016-10-24T04:11:39,386  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: 0: get_table : db=default tbl=wikiticker_kafka
4022016-10-24T04:11:39,386  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] HiveMetaStore.audit: ugi=vagrant	ip=unknown-ip-addr	cmd=get_table : db=default tbl=wikiticker_kafka
4032016-10-24T04:11:39,386 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
404	org.apache.hadoop.hive.metastore.ObjectStore.getTable(ObjectStore.java:1187)
4052016-10-24T04:11:39,386 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Open transaction: count = 2, isActive = true at:
406	org.apache.hadoop.hive.metastore.ObjectStore.getMTable(ObjectStore.java:1389)
4072016-10-24T04:11:39,393 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 1, isactive true at:
408	org.apache.hadoop.hive.metastore.ObjectStore.getMTable(ObjectStore.java:1403)
4092016-10-24T04:11:39,405 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
410	org.apache.hadoop.hive.metastore.ObjectStore.getTable(ObjectStore.java:1189)
4112016-10-24T04:11:39,410  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Get metadata for subqueries
4122016-10-24T04:11:39,411  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Get metadata for destination tables
4132016-10-24T04:11:39,412 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #66
4142016-10-24T04:11:39,413 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #66
4152016-10-24T04:11:39,413 DEBUG [main] ipc.ProtobufRpcEngine: Call: getEZForPath took 2ms
4162016-10-24T04:11:39,413  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Context: New scratch dir is hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1
4172016-10-24T04:11:39,413 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] hive.log: DDL: struct wikiticker_kafka { timestamp __time, float added, string channel, string comment, i64 count, float deleted, float delta, string diffurl, string flags, string isminor, string isnew, string isrobot, string isunpatrolled, string namespace, string page, string user, string user_unique}
4182016-10-24T04:11:39,443 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] serde.DruidSerDe: DruidSerDe initialized with
419	 columns: [__time, channel, comment, diffurl, flags, isminor, isnew, isrobot, isunpatrolled, namespace, page, user, user_unique, added, count, deleted, delta]
420	 types: [timestamp, string, string, string, string, string, string, string, string, string, string, string, string, float, float, float, float]
4212016-10-24T04:11:39,501 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created Table Plan for wikiticker_kafka TS[0]
4222016-10-24T04:11:39,501 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: RR before GB wikiticker_kafka{(__time,__time: timestamp)(channel,channel: string)(comment,comment: string)(diffurl,diffurl: string)(flags,flags: string)(isminor,isminor: string)(isnew,isnew: string)(isrobot,isrobot: string)(isunpatrolled,isunpatrolled: string)(namespace,namespace: string)(page,page: string)(user,user: string)(user_unique,user_unique: string)(added,added: float)(count,count: float)(deleted,deleted: float)(delta,delta: float)(block__offset__inside__file,BLOCK__OFFSET__INSIDE__FILE: bigint)(input__file__name,INPUT__FILE__NAME: string)(row__id,ROW__ID: struct<transactionid:bigint,bucketid:int,rowid:bigint>)}  after GB wikiticker_kafka{(__time,__time: timestamp)(channel,channel: string)(comment,comment: string)(diffurl,diffurl: string)(flags,flags: string)(isminor,isminor: string)(isnew,isnew: string)(isrobot,isrobot: string)(isunpatrolled,isunpatrolled: string)(namespace,namespace: string)(page,page: string)(user,user: string)(user_unique,user_unique: string)(added,added: float)(count,count: float)(deleted,deleted: float)(delta,delta: float)(block__offset__inside__file,BLOCK__OFFSET__INSIDE__FILE: bigint)(input__file__name,INPUT__FILE__NAME: string)(row__id,ROW__ID: struct<transactionid:bigint,bucketid:int,rowid:bigint>)}
4232016-10-24T04:11:39,502 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: tree: (tok_select (tok_selexpr (. (tok_table_or_col wikiticker_kafka) __time) wikiticker_kafka.__time) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) added) wikiticker_kafka.added) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) channel) wikiticker_kafka.channel) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) comment) wikiticker_kafka.comment) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) count) wikiticker_kafka.count) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) deleted) wikiticker_kafka.deleted) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) delta) wikiticker_kafka.delta) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) diffurl) wikiticker_kafka.diffurl) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) flags) wikiticker_kafka.flags) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) isminor) wikiticker_kafka.isminor) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) isnew) wikiticker_kafka.isnew) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) isrobot) wikiticker_kafka.isrobot) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) isunpatrolled) wikiticker_kafka.isunpatrolled) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) namespace) wikiticker_kafka.namespace) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) page) wikiticker_kafka.page) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) user) wikiticker_kafka.user) (tok_selexpr (. (tok_table_or_col wikiticker_kafka) user_unique) wikiticker_kafka.user_unique))
4242016-10-24T04:11:39,502 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: genSelectPlan: input = wikiticker_kafka{(__time,__time: timestamp)(channel,channel: string)(comment,comment: string)(diffurl,diffurl: string)(flags,flags: string)(isminor,isminor: string)(isnew,isnew: string)(isrobot,isrobot: string)(isunpatrolled,isunpatrolled: string)(namespace,namespace: string)(page,page: string)(user,user: string)(user_unique,user_unique: string)(added,added: float)(count,count: float)(deleted,deleted: float)(delta,delta: float)(block__offset__inside__file,BLOCK__OFFSET__INSIDE__FILE: bigint)(input__file__name,INPUT__FILE__NAME: string)(row__id,ROW__ID: struct<transactionid:bigint,bucketid:int,rowid:bigint>)}  starRr = null
4252016-10-24T04:11:39,522 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created Select Plan row schema: null{(wikiticker_kafka.__time,_col0: timestamp)(wikiticker_kafka.added,_col1: float)(wikiticker_kafka.channel,_col2: string)(wikiticker_kafka.comment,_col3: string)(wikiticker_kafka.count,_col4: float)(wikiticker_kafka.deleted,_col5: float)(wikiticker_kafka.delta,_col6: float)(wikiticker_kafka.diffurl,_col7: string)(wikiticker_kafka.flags,_col8: string)(wikiticker_kafka.isminor,_col9: string)(wikiticker_kafka.isnew,_col10: string)(wikiticker_kafka.isrobot,_col11: string)(wikiticker_kafka.isunpatrolled,_col12: string)(wikiticker_kafka.namespace,_col13: string)(wikiticker_kafka.page,_col14: string)(wikiticker_kafka.user,_col15: string)(wikiticker_kafka.user_unique,_col16: string)}
4262016-10-24T04:11:39,522 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created Select Plan for clause: insclause-0
4272016-10-24T04:11:39,524 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Context: Created staging dir = hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001/.hive-staging_hive_2016-10-24_04-11-35_449_4498052868715744026-1 for path = hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001
4282016-10-24T04:11:39,525 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #67
4292016-10-24T04:11:39,526 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #67
4302016-10-24T04:11:39,527 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
4312016-10-24T04:11:39,527 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #68
4322016-10-24T04:11:39,528 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #68
4332016-10-24T04:11:39,528 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
4342016-10-24T04:11:39,529 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #69
4352016-10-24T04:11:39,530 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #69
4362016-10-24T04:11:39,530 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 2ms
4372016-10-24T04:11:39,530 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #70
4382016-10-24T04:11:39,531 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #70
4392016-10-24T04:11:39,532 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 2ms
4402016-10-24T04:11:39,532 DEBUG [main] hdfs.DFSClient: /tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001/.hive-staging_hive_2016-10-24_04-11-35_449_4498052868715744026-1: masked=rwxr-xr-x
4412016-10-24T04:11:39,532 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #71
4422016-10-24T04:11:39,534 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #71
4432016-10-24T04:11:39,534 DEBUG [main] ipc.ProtobufRpcEngine: Call: mkdirs took 2ms
4442016-10-24T04:11:39,535 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #72
4452016-10-24T04:11:39,536 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #72
4462016-10-24T04:11:39,536 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
4472016-10-24T04:11:39,549 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] shims.HdfsUtils: {-chgrp,-R,hdfs,hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001}
4482016-10-24T04:11:39,599 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #73
4492016-10-24T04:11:39,600 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #73
4502016-10-24T04:11:39,600 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
4512016-10-24T04:11:39,605 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #74
4522016-10-24T04:11:39,606 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #74
4532016-10-24T04:11:39,607 DEBUG [main] ipc.ProtobufRpcEngine: Call: getListing took 2ms
4542016-10-24T04:11:39,613 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #75
4552016-10-24T04:11:39,614 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #75
4562016-10-24T04:11:39,614 DEBUG [main] ipc.ProtobufRpcEngine: Call: getListing took 1ms
4572016-10-24T04:11:39,615 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] shims.HdfsUtils: Return value is :0
4582016-10-24T04:11:39,615 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] shims.HdfsUtils: {-chmod,-R,700,hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001}
4592016-10-24T04:11:39,617 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #76
4602016-10-24T04:11:39,618 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #76
4612016-10-24T04:11:39,618 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
4622016-10-24T04:11:39,618 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #77
4632016-10-24T04:11:39,620 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #77
4642016-10-24T04:11:39,620 DEBUG [main] ipc.ProtobufRpcEngine: Call: setPermission took 2ms
4652016-10-24T04:11:39,620 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #78
4662016-10-24T04:11:39,621 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #78
4672016-10-24T04:11:39,621 DEBUG [main] ipc.ProtobufRpcEngine: Call: getListing took 1ms
4682016-10-24T04:11:39,622 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #79
4692016-10-24T04:11:39,623 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #79
4702016-10-24T04:11:39,623 DEBUG [main] ipc.ProtobufRpcEngine: Call: setPermission took 2ms
4712016-10-24T04:11:39,624 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #80
4722016-10-24T04:11:39,624 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #80
4732016-10-24T04:11:39,625 DEBUG [main] ipc.ProtobufRpcEngine: Call: getListing took 1ms
4742016-10-24T04:11:39,625 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] shims.HdfsUtils: Return value is :0
4752016-10-24T04:11:39,625 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #81
4762016-10-24T04:11:39,626 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #81
4772016-10-24T04:11:39,626 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
4782016-10-24T04:11:39,638 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] lazy.LazySerDeParameters: org.apache.hadoop.hive.serde2.lazy.LazySimpleSerDe initialized with: columnNames=[_col0, _col1, _col2, _col3, _col4, _col5, _col6, _col7, _col8, _col9, _col10, _col11, _col12, _col13, _col14, _col15, _col16] columnTypes=[timestamp, float, string, string, float, float, float, string, string, string, string, string, string, string, string, string, string] separator=[[B@707e7c95] nullstring=\N lastColumnTakesRest=false timestampFormats=null
4792016-10-24T04:11:39,661 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] lazy.LazySerDeParameters: org.apache.hadoop.hive.serde2.lazy.LazySimpleSerDe initialized with: columnNames=[_col0, _col1, _col2, _col3, _col4, _col5, _col6, _col7, _col8, _col9, _col10, _col11, _col12, _col13, _col14, _col15, _col16] columnTypes=[timestamp, float, string, string, float, float, float, string, string, string, string, string, string, string, string, string, string] separator=[[B@67699068] nullstring=\N lastColumnTakesRest=false timestampFormats=null
4802016-10-24T04:11:39,662 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Set stats collection dir : hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001/.hive-staging_hive_2016-10-24_04-11-35_449_4498052868715744026-1/-ext-10003
4812016-10-24T04:11:39,666 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created FileSink Plan for clause: insclause-0dest_path: hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001 row schema: null{(wikiticker_kafka.__time,_col0: timestamp)(wikiticker_kafka.added,_col1: float)(wikiticker_kafka.channel,_col2: string)(wikiticker_kafka.comment,_col3: string)(wikiticker_kafka.count,_col4: float)(wikiticker_kafka.deleted,_col5: float)(wikiticker_kafka.delta,_col6: float)(wikiticker_kafka.diffurl,_col7: string)(wikiticker_kafka.flags,_col8: string)(wikiticker_kafka.isminor,_col9: string)(wikiticker_kafka.isnew,_col10: string)(wikiticker_kafka.isrobot,_col11: string)(wikiticker_kafka.isunpatrolled,_col12: string)(wikiticker_kafka.namespace,_col13: string)(wikiticker_kafka.page,_col14: string)(wikiticker_kafka.user,_col15: string)(wikiticker_kafka.user_unique,_col16: string)}
4822016-10-24T04:11:39,666 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created Body Plan for Query Block null
4832016-10-24T04:11:39,666 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Created Plan for Query Block null
4842016-10-24T04:11:39,666  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: CBO Succeeded; optimized logical plan.
4852016-10-24T04:11:39,668 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Before logical optimization
486TS[0]-SEL[1]-FS[2]
4872016-10-24T04:11:39,725  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ppd.OpProcFactory: Processing for FS(2)
4882016-10-24T04:11:39,725  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ppd.OpProcFactory: Processing for SEL(1)
4892016-10-24T04:11:39,725  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ppd.OpProcFactory: Processing for TS(0)
4902016-10-24T04:11:39,725 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ppd.SimplePredicatePushDown: After PPD:
491TS[0]-SEL[1]-FS[2]
4922016-10-24T04:11:39,776 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] hive.log: DDL: struct wikiticker_kafka { timestamp __time, float added, string channel, string comment, i64 count, float deleted, float delta, string diffurl, string flags, string isminor, string isnew, string isrobot, string isunpatrolled, string namespace, string page, string user, string user_unique}
4932016-10-24T04:11:39,781 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: After logical optimization
494TS[0]-SEL[1]-LIST_SINK[3]
4952016-10-24T04:11:39,790  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: Completed plan generation
4962016-10-24T04:11:39,790  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Semantic Analysis Completed
4972016-10-24T04:11:39,790 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: validation start
4982016-10-24T04:11:39,791 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] parse.CalcitePlanner: not validating writeEntity, because entity is neither table nor partition
4992016-10-24T04:11:39,793  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:wikiticker_kafka.__time, type:timestamp, comment:null), FieldSchema(name:wikiticker_kafka.added, type:float, comment:null), FieldSchema(name:wikiticker_kafka.channel, type:string, comment:null), FieldSchema(name:wikiticker_kafka.comment, type:string, comment:null), FieldSchema(name:wikiticker_kafka.count, type:float, comment:null), FieldSchema(name:wikiticker_kafka.deleted, type:float, comment:null), FieldSchema(name:wikiticker_kafka.delta, type:float, comment:null), FieldSchema(name:wikiticker_kafka.diffurl, type:string, comment:null), FieldSchema(name:wikiticker_kafka.flags, type:string, comment:null), FieldSchema(name:wikiticker_kafka.isminor, type:string, comment:null), FieldSchema(name:wikiticker_kafka.isnew, type:string, comment:null), FieldSchema(name:wikiticker_kafka.isrobot, type:string, comment:null), FieldSchema(name:wikiticker_kafka.isunpatrolled, type:string, comment:null), FieldSchema(name:wikiticker_kafka.namespace, type:string, comment:null), FieldSchema(name:wikiticker_kafka.page, type:string, comment:null), FieldSchema(name:wikiticker_kafka.user, type:string, comment:null), FieldSchema(name:wikiticker_kafka.user_unique, type:string, comment:null)], properties:null)
5002016-10-24T04:11:39,815 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] serde.DruidSerDe: DruidSerDe initialized with
501	 columns: [__time, channel, comment, diffurl, flags, isminor, isnew, isrobot, isunpatrolled, namespace, page, user, user_unique, added, count, deleted, delta]
502	 types: [timestamp, string, string, string, string, string, string, string, string, string, string, string, string, float, float, float, float]
5032016-10-24T04:11:39,818  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: Initializing operator TS[0]
5042016-10-24T04:11:39,819 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: Initialization Done 0 TS
5052016-10-24T04:11:39,819 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: Operator 0 TS initialized
5062016-10-24T04:11:39,819 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: Initializing children of 0 TS
5072016-10-24T04:11:39,819 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Initializing child 1 SEL
5082016-10-24T04:11:39,819  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Initializing operator SEL[1]
5092016-10-24T04:11:39,825  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: SELECT struct<__time:timestamp,channel:string,comment:string,diffurl:string,flags:string,isminor:string,isnew:string,isrobot:string,isunpatrolled:string,namespace:string,page:string,user:string,user_unique:string,added:float,count:float,deleted:float,delta:float>
5102016-10-24T04:11:39,826 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Initialization Done 1 SEL
5112016-10-24T04:11:39,826 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Operator 1 SEL initialized
5122016-10-24T04:11:39,826 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Initializing children of 1 SEL
5132016-10-24T04:11:39,826 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: Initializing child 3 LIST_SINK
5142016-10-24T04:11:39,826  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: Initializing operator LIST_SINK[3]
5152016-10-24T04:11:39,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] lazy.LazySerDeParameters: org.apache.hadoop.hive.serde2.DelimitedJSONSerDe initialized with: columnNames=[] columnTypes=[] separator=[[B@3a050cc8] nullstring=NULL lastColumnTakesRest=false timestampFormats=null
5162016-10-24T04:11:39,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: Initialization Done 3 LIST_SINK
5172016-10-24T04:11:39,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: Operator 3 LIST_SINK initialized
5182016-10-24T04:11:39,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: Initialization Done 3 LIST_SINK done is reset.
5192016-10-24T04:11:39,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Initialization Done 1 SEL done is reset.
5202016-10-24T04:11:39,828 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: Initialization Done 0 TS done is reset.
5212016-10-24T04:11:39,837 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #82
5222016-10-24T04:11:39,838 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #82
5232016-10-24T04:11:39,838 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 2ms
5242016-10-24T04:11:39,841 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #83
5252016-10-24T04:11:39,842 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #83
5262016-10-24T04:11:39,842 DEBUG [main] ipc.ProtobufRpcEngine: Call: checkAccess took 1ms
5272016-10-24T04:11:39,845  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metadata.Hive: Dumping metastore api call timing information for : compilation phase
5282016-10-24T04:11:39,845 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metadata.Hive: Total time spent in each metastore function (ms): {flushCache_()=0, getTable_(String, String, )=103, isCompatibleWith_(HiveConf, )=0, getAllFunctions_()=6}
5292016-10-24T04:11:39,845  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Completed compiling command(queryId=vagrant_20161024041135_87e818a1-e564-46c7-a50b-a0e14d1c9513); Time taken: 4.427 seconds
5302016-10-24T04:11:39,846  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Concurrency mode is disabled, not creating a lock manager
5312016-10-24T04:11:39,846  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Executing command(queryId=vagrant_20161024041135_87e818a1-e564-46c7-a50b-a0e14d1c9513): select * from wikiticker_kafka
5322016-10-24T04:11:39,849 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] service.AbstractService: Service: org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl entered state INITED
5332016-10-24T04:11:39,884 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ssl.FileBasedKeyStoresFactory: The property 'ssl.client.truststore.location' has not been set, no TrustStore will be loaded
5342016-10-24T04:11:39,972  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] impl.TimelineClientImpl: Timeline service address: http://druid.example.com:8188/ws/v1/timeline/
5352016-10-24T04:11:39,973 DEBUG [main] hdfs.BlockReaderLocal: dfs.client.use.legacy.blockreader.local = false
5362016-10-24T04:11:39,973 DEBUG [main] hdfs.BlockReaderLocal: dfs.client.read.shortcircuit = true
5372016-10-24T04:11:39,973 DEBUG [main] hdfs.BlockReaderLocal: dfs.client.domain.socket.data.traffic = false
5382016-10-24T04:11:39,973 DEBUG [main] hdfs.BlockReaderLocal: dfs.domain.socket.path = /var/lib/hadoop/hdfs/dn_socket
5392016-10-24T04:11:39,974 DEBUG [main] retry.RetryUtils: multipleLinearRandomRetry = MultipleLinearRandomRetry[500x2000ms]
5402016-10-24T04:11:39,974 DEBUG [main] ipc.Client: getting client out of cache: org.apache.hadoop.ipc.Client@35a6e9ee
5412016-10-24T04:11:39,974 DEBUG [main] sasl.DataTransferSaslUtil: DataTransferProtocol not using SaslPropertiesResolver, no QOP found in configuration for dfs.data.transfer.protection
5422016-10-24T04:11:39,975 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #84
5432016-10-24T04:11:39,976 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #84
5442016-10-24T04:11:39,976 DEBUG [main] ipc.ProtobufRpcEngine: Call: getFileInfo took 1ms
5452016-10-24T04:11:39,977 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] impl.FileSystemTimelineWriter: yarn.timeline-service.client.fd-flush-interval-secs=10, yarn.timeline-service.client.fd-clean-interval-secs=60, yarn.timeline-service.client.fd-retain-secs=300, yarn.timeline-service.entity-file.fs-support-append=true, yarn.timeline-service.entity-group-fs-store.active-dir=/tmp/entity-file-history/active
5462016-10-24T04:11:39,977 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] service.AbstractService: Service org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl is started
5472016-10-24T04:11:39,978  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] hooks.ATSHook: Created ATS Hook
5482016-10-24T04:11:39,981  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] hooks.ATSHook: Created ATS Hook
5492016-10-24T04:11:39,982  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metadata.Hive: Dumping metastore api call timing information for : execution phase
550OK2016-10-24T04:11:39,982 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metadata.Hive: Total time spent in each metastore function (ms): {}
551
5522016-10-24T04:11:39,982  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Completed executing command(queryId=vagrant_20161024041135_87e818a1-e564-46c7-a50b-a0e14d1c9513); Time taken: 0.136 seconds
5532016-10-24T04:11:39,982  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: OK
5542016-10-24T04:11:39,983 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Driver: Shutting down query select * from wikiticker_kafka
555Failed with exception java.io.IOException:java.io.IOException: Druid query type not recognized
5562016-10-24T04:11:40,000 ERROR [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] CliDriver: Failed with exception java.io.IOException:java.io.IOException: Druid query type not recognized
557java.io.IOException: java.io.IOException: Druid query type not recognized
558	at org.apache.hadoop.hive.ql.exec.FetchOperator.getNextRow(FetchOperator.java:521)
559	at org.apache.hadoop.hive.ql.exec.FetchOperator.pushRow(FetchOperator.java:428)
560	at org.apache.hadoop.hive.ql.exec.FetchTask.fetch(FetchTask.java:147)
561	at org.apache.hadoop.hive.ql.Driver.getResults(Driver.java:2192)
562	at org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:253)
563	at org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:184)
564	at org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:400)
565	at org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:777)
566	at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:715)
567	at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:642)
568	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
569	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
570	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
571	at java.lang.reflect.Method.invoke(Method.java:606)
572	at org.apache.hadoop.util.RunJar.run(RunJar.java:233)
573	at org.apache.hadoop.util.RunJar.main(RunJar.java:148)
574Caused by: java.io.IOException: Druid query type not recognized
575	at org.apache.hadoop.hive.druid.HiveDruidQueryBasedInputFormat.getInputSplits(HiveDruidQueryBasedInputFormat.java:140)
576	at org.apache.hadoop.hive.druid.HiveDruidQueryBasedInputFormat.getSplits(HiveDruidQueryBasedInputFormat.java:91)
577	at org.apache.hadoop.hive.ql.exec.FetchOperator.getNextSplits(FetchOperator.java:372)
578	at org.apache.hadoop.hive.ql.exec.FetchOperator.getRecordReader(FetchOperator.java:304)
579	at org.apache.hadoop.hive.ql.exec.FetchOperator.getNextRow(FetchOperator.java:459)
580	... 15 more
581
5822016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: 0 finished. closing...
5832016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: Closing child = SEL[1]
5842016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: allInitializedParentsAreClosed? parent.state = CLOSE
5852016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: 1 finished. closing...
5862016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: Closing child = LIST_SINK[3]
5872016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: allInitializedParentsAreClosed? parent.state = CLOSE
5882016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: 3 finished. closing...
5892016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.ListSinkOperator: 3 Close done
5902016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.SelectOperator: 1 Close done
5912016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] exec.TableScanOperator: 0 Close done
5922016-10-24T04:11:40,000 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Context: Deleting result dir: hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001
5932016-10-24T04:11:40,003 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #85
5942016-10-24T04:11:40,009 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #85
5952016-10-24T04:11:40,009 DEBUG [main] ipc.ProtobufRpcEngine: Call: delete took 6ms
5962016-10-24T04:11:40,012 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Context: Deleting scratch dir: hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1/-mr-10001/.hive-staging_hive_2016-10-24_04-11-35_449_4498052868715744026-1
5972016-10-24T04:11:40,013 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #86
5982016-10-24T04:11:40,013 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #86
5992016-10-24T04:11:40,014 DEBUG [main] ipc.ProtobufRpcEngine: Call: delete took 2ms
6002016-10-24T04:11:40,014 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] ql.Context: Deleting scratch dir: hdfs://druid.example.com:8020/tmp/hive/vagrant/13c1b27b-2b7b-4be5-b7db-c4b70c7defa5/hive_2016-10-24_04-11-35_449_4498052868715744026-1
6012016-10-24T04:11:40,015 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #87
6022016-10-24T04:11:40,016 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #87
6032016-10-24T04:11:40,016 DEBUG [main] ipc.ProtobufRpcEngine: Call: delete took 1ms
604Time taken: 4.569 seconds
6052016-10-24T04:11:40,017  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] CliDriver: Time taken: 4.569 seconds
606hive>
607    > 2016-10-24T04:11:44,101  INFO [main] tez.TezSessionPoolManager: Closing tez session if not default: sessionId=13c1b27b-2b7b-4be5-b7db-c4b70c7defa5, queueName=null, user=vagrant, doAs=false, isOpen=true, isDefault=false
6082016-10-24T04:11:44,101  INFO [main] tez.TezSessionState: Closing Tez Session
6092016-10-24T04:11:44,102 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] service.AbstractService: Service: org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl entered state STOPPED
6102016-10-24T04:11:44,102 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] impl.FileSystemTimelineWriter: Closing cache
6112016-10-24T04:11:44,102 DEBUG [main] ipc.Client: stopping client from cache: org.apache.hadoop.ipc.Client@35a6e9ee
6122016-10-24T04:11:44,103  INFO [main] client.TezClient: Shutting down Tez Session, sessionName=HIVE-13c1b27b-2b7b-4be5-b7db-c4b70c7defa5, applicationId=application_1477271342121_0008
6132016-10-24T04:11:44,104 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8050 from vagrant sending #88
6142016-10-24T04:11:44,105 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8050 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8050 from vagrant got value #88
6152016-10-24T04:11:44,106 DEBUG [main] ipc.ProtobufRpcEngine: Call: getApplicationReport took 2ms
6162016-10-24T04:11:44,106 DEBUG [main] client.TezClientUtils: Connecting to Tez AM at druid.example.com/192.168.59.31:36568
6172016-10-24T04:11:44,106 DEBUG [main] security.UserGroupInformation: PrivilegedAction as:vagrant (auth:SIMPLE) from:org.apache.tez.client.TezClientUtils.getAMProxy(TezClientUtils.java:968)
6182016-10-24T04:11:44,107 DEBUG [main] ipc.Client: getting client out of cache: org.apache.hadoop.ipc.Client@35a6e9ee
6192016-10-24T04:11:44,109 DEBUG [main] ipc.Client: The ping interval is 60000 ms.
6202016-10-24T04:11:44,109 DEBUG [main] ipc.Client: Connecting to druid.example.com/192.168.59.31:36568
6212016-10-24T04:11:44,110 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:36568 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:36568 from vagrant: starting, having connections 5
6222016-10-24T04:11:44,111 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:36568 from vagrant sending #89
6232016-10-24T04:11:44,118 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:36568 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:36568 from vagrant got value #89
6242016-10-24T04:11:44,118 DEBUG [main] ipc.ProtobufRpcEngine: Call: shutdownSession took 9ms
6252016-10-24T04:11:44,121 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] service.AbstractService: Service: org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state STOPPED
6262016-10-24T04:11:44,121 DEBUG [main] ipc.Client: stopping client from cache: org.apache.hadoop.ipc.Client@35a6e9ee
6272016-10-24T04:11:44,121 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] service.AbstractService: Service: org.apache.hadoop.yarn.client.api.impl.AHSClientImpl entered state STOPPED
6282016-10-24T04:11:44,121 DEBUG [main] ipc.Client: stopping client from cache: org.apache.hadoop.ipc.Client@35a6e9ee
6292016-10-24T04:11:44,122 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] service.AbstractService: Service: org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl entered state STOPPED
6302016-10-24T04:11:44,122 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] impl.FileSystemTimelineWriter: Closing cache
6312016-10-24T04:11:44,122 DEBUG [main] ipc.Client: stopping client from cache: org.apache.hadoop.ipc.Client@35a6e9ee
6322016-10-24T04:11:44,123 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #90
6332016-10-24T04:11:44,125 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #90
6342016-10-24T04:11:44,125 DEBUG [main] ipc.ProtobufRpcEngine: Call: delete took 2ms
6352016-10-24T04:11:44,126 DEBUG [IPC Parameter Sending Thread #0] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant sending #91
6362016-10-24T04:11:44,127 DEBUG [IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant] ipc.Client: IPC Client (219889431) connection to druid.example.com/192.168.59.31:8020 from vagrant got value #91
6372016-10-24T04:11:44,127 DEBUG [main] ipc.ProtobufRpcEngine: Call: delete took 2ms
6382016-10-24T04:11:44,132 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: Removed cached classloaders from DataNucleus NucleusContext
6392016-10-24T04:11:44,132 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metadata.Hive: Closing current thread's connection to Hive Metastore.
6402016-10-24T04:11:44,133  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: 0: Cleaning up thread local RawStore...
6412016-10-24T04:11:44,133  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] HiveMetaStore.audit: ugi=vagrant	ip=unknown-ip-addr	cmd=Cleaning up thread local RawStore...
6422016-10-24T04:11:44,133 DEBUG [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@82a85f2, with PersistenceManager: org.datanucleus.api.jdo.JDOPersistenceManager@114a56f6 will be shutdown
6432016-10-24T04:11:44,133  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] metastore.HiveMetaStore: 0: Done cleaning up thread local RawStore
6442016-10-24T04:11:44,133  INFO [13c1b27b-2b7b-4be5-b7db-c4b70c7defa5 main] HiveMetaStore.audit: ugi=vagrant	ip=unknown-ip-addr	cmd=Done cleaning up thread local RawStore
6452016-10-24T04:11:44,136 DEBUG [pool-2-thread-1] service.AbstractService: Service: org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl entered state STOPPED
6462016-10-24T04:11:44,137 DEBUG [pool-2-thread-1] impl.FileSystemTimelineWriter: Closing cache
6472016-10-24T04:11:44,137 DEBUG [pool-2-thread-1] ipc.Client: stopping client from cache: org.apache.hadoop.ipc.Client@35a6e9ee
6482016-10-24T04:11:44,138 DEBUG [pool-2-thread-1] ipc.Client: stopping client from cache: org.apache.hadoop.ipc.Client@35a6e9ee