```bash=
2023-05-08T01:03:01,111 DEBUG [pool-6-thread-15] metrics.PerfLogger: <PERFLOG method=get_all_databases from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-05-08T01:03:01,111 INFO [pool-6-thread-15] metastore.HiveMetaStore: 15: source:10.0.201.237 get_databases: @hive#
2023-05-08T01:03:01,111 INFO [pool-6-thread-15] HiveMetaStore.audit: ugi=root ip=10.0.201.237 cmd=source:10.0.201.237 get_databases: @hive#
2023-05-08T01:03:01,120 INFO [pool-6-thread-15] metastore.HiveMetaStore: 15: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
2023-05-08T01:03:01,120 WARN [pool-6-thread-15] metastore.ObjectStore: datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored
2023-05-08T01:03:01,120 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.schema.autoCreateAll value null from jpox.properties with false
2023-05-08T01:03:01,120 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionDriverName value null from jpox.properties with org.postgresql.Driver
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.connectionPool.maxPoolSize value null from jpox.properties with 10
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.connectionPoolingType value null from jpox.properties with HikariCP
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionURL value null from jpox.properties with jdbc:postgresql://lighthouse-outpost-dev-hivemetastoredb.cm25znb924dp.ap-northeast-1.rds.amazonaws.com:5432/hivemetastoredb?allowPublicKeyRetrieval=true&useSSL=false&serverTimezone=UTC
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionUserName value null from jpox.properties with postgres
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.autoStartMechanismMode value null from jpox.properties with ignored
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.cache.level2 value null from jpox.properties with false
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.cache.level2.type value null from jpox.properties with none
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.rdbms.initializeColumnInfo value null from jpox.properties with NONE
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.plugin.pluginRegistryBundleCheck value null from jpox.properties with LOG
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.transactionIsolation value null from jpox.properties with read-committed
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.rdbms.useLegacyNativeValueStrategy value null from jpox.properties with true
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.option.DetachAllOnCommit value null from jpox.properties with true
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.identifierFactory value null from jpox.properties with datanucleus1
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.PersistenceManagerFactoryClass value null from jpox.properties with org.datanucleus.api.jdo.JDOPersistenceManagerFactory
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.option.Multithreaded value null from jpox.properties with true
2023-05-08T01:03:01,121 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding javax.jdo.option.NonTransactionalRead value null from jpox.properties with true
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.storeManagerType value null from jpox.properties with rdbms
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.schema.validateColumns value null from jpox.properties with false
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.schema.validateConstraints value null from jpox.properties with false
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: Overriding datanucleus.schema.validateTables value null from jpox.properties with false
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.rdbms.useLegacyNativeValueStrategy = true
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.schema.validateConstraints = false
2023-05-08T01:03:01,122 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.option.ConnectionUserName = postgres
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.storeManagerType = rdbms
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.option.ConnectionDriverName = org.postgresql.Driver
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.cache.level2.type = none
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.option.NonTransactionalRead = true
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.option.ConnectionURL = jdbc:postgresql://lighthouse-outpost-dev-hivemetastoredb.cm25znb924dp.ap-northeast-1.rds.amazonaws.com:5432/hivemetastoredb?allowPublicKeyRetrieval=true&useSSL=false&serverTimezone=UTC
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.connectionPool.maxPoolSize = 10
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.rdbms.initializeColumnInfo = NONE
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.connectionPoolingType = HikariCP
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.schema.validateColumns = false
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.transactionIsolation = read-committed
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.cache.level2 = false
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.schema.autoCreateAll = false
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.identifierFactory = datanucleus1
2023-05-08T01:03:01,126 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.option.Multithreaded = true
2023-05-08T01:03:01,127 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.plugin.pluginRegistryBundleCheck = LOG
2023-05-08T01:03:01,127 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.PersistenceManagerFactoryClass = org.datanucleus.api.jdo.JDOPersistenceManagerFactory
2023-05-08T01:03:01,127 DEBUG [pool-6-thread-15] metastore.ObjectStore: javax.jdo.option.DetachAllOnCommit = true
2023-05-08T01:03:01,127 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.schema.validateTables = false
2023-05-08T01:03:01,127 DEBUG [pool-6-thread-15] metastore.ObjectStore: datanucleus.autoStartMechanismMode = ignored
2023-05-08T01:03:01,127 DEBUG [pool-6-thread-15] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@4746ecf4, with PersistenceManager: null will be shutdown
2023-05-08T01:03:01,127 INFO [pool-6-thread-15] metastore.ObjectStore: ObjectStore, initialize called
2023-05-08T01:03:01,136 DEBUG [pool-6-thread-15] pool.PoolBase: HikariPool-2 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@4cf46574
2023-05-08T01:03:01,136 DEBUG [pool-6-thread-15] pool.PoolBase: HikariPool-2 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@4cf46574
2023-05-08T01:03:01,137 DEBUG [pool-6-thread-15] pool.PoolBase: HikariPool-2 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@4cf46574
2023-05-08T01:03:01,141 DEBUG [pool-6-thread-15] pool.PoolBase: HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@5fdcc63f
2023-05-08T01:03:01,141 INFO [pool-6-thread-15] metastore.MetaStoreDirectSql: Using direct SQL, underlying DB is POSTGRES
2023-05-08T01:03:01,141 DEBUG [pool-6-thread-15] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@4746ecf4, with PersistenceManager: org.datanucleus.api.jdo.JDOPersistenceManager@2fdfdced created in the thread with id: 40
2023-05-08T01:03:01,141 INFO [pool-6-thread-15] metastore.ObjectStore: Initialized ObjectStore
2023-05-08T01:03:01,141 DEBUG [pool-6-thread-15] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore.getAllDatabases(ObjectStore.java:1151)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-05-08T01:03:01,143 DEBUG [pool-6-thread-15] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore.getAllDatabases(ObjectStore.java:1158)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2023-05-08T01:03:01,143 DEBUG [pool-6-thread-15] pool.PoolBase: HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@5fdcc63f
2023-05-08T01:03:01,144 DEBUG [pool-6-thread-15] metrics.PerfLogger: </PERFLOG method=get_all_databases start=1683507781111 end=1683507781144 duration=33 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=15 retryCount=0 error=false>
2023-05-08T01:03:01,147 INFO [pool-6-thread-15] metastore.HiveMetaStore: 15: Cleaning up thread local RawStore...
2023-05-08T01:03:01,147 INFO [pool-6-thread-15] HiveMetaStore.audit: ugi=root ip=10.0.201.237 cmd=Cleaning up thread local RawStore...
2023-05-08T01:03:01,147 DEBUG [pool-6-thread-15] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@4746ecf4, with PersistenceManager: org.datanucleus.api.jdo.JDOPersistenceManager@2fdfdced will be shutdown
2023-05-08T01:03:01,147 INFO [pool-6-thread-15] metastore.HiveMetaStore: 15: Done cleaning up thread local RawStore
2023-05-08T01:03:01,147 INFO [pool-6-thread-15] HiveMetaStore.audit: ugi=root ip=10.0.201.237 cmd=Done cleaning up thread local RawStore
2023-05-08T01:03:01,161 DEBUG [pool-6-thread-16] metrics.PerfLogger: <PERFLOG method=create_database from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-05-08T01:03:01,161 INFO [pool-6-thread-16] metastore.HiveMetaStore: 16: source:10.0.201.237 create_database: Database(name:test, description:null, locationUri:s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test, parameters:{presto_query_id=20230508_010300_00003_xfd6k}, ownerName:trino, ownerType:USER)
2023-05-08T01:03:01,161 INFO [pool-6-thread-16] HiveMetaStore.audit: ugi=root ip=10.0.201.237 cmd=source:10.0.201.237 create_database: Database(name:test, description:null, locationUri:s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test, parameters:{presto_query_id=20230508_010300_00003_xfd6k}, ownerName:trino, ownerType:USER)
2023-05-08T01:03:01,166 INFO [pool-6-thread-16] metastore.HiveMetaStore: 16: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
2023-05-08T01:03:01,166 WARN [pool-6-thread-16] metastore.ObjectStore: datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.schema.autoCreateAll value null from jpox.properties with false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionDriverName value null from jpox.properties with org.postgresql.Driver
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.connectionPool.maxPoolSize value null from jpox.properties with 10
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.connectionPoolingType value null from jpox.properties with HikariCP
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionURL value null from jpox.properties with jdbc:postgresql://lighthouse-outpost-dev-hivemetastoredb.cm25znb924dp.ap-northeast-1.rds.amazonaws.com:5432/hivemetastoredb?allowPublicKeyRetrieval=true&useSSL=false&serverTimezone=UTC
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.option.ConnectionUserName value null from jpox.properties with postgres
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.autoStartMechanismMode value null from jpox.properties with ignored
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.cache.level2 value null from jpox.properties with false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.cache.level2.type value null from jpox.properties with none
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.rdbms.initializeColumnInfo value null from jpox.properties with NONE
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.plugin.pluginRegistryBundleCheck value null from jpox.properties with LOG
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.transactionIsolation value null from jpox.properties with read-committed
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.rdbms.useLegacyNativeValueStrategy value null from jpox.properties with true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.option.DetachAllOnCommit value null from jpox.properties with true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.identifierFactory value null from jpox.properties with datanucleus1
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.PersistenceManagerFactoryClass value null from jpox.properties with org.datanucleus.api.jdo.JDOPersistenceManagerFactory
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.option.Multithreaded value null from jpox.properties with true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding javax.jdo.option.NonTransactionalRead value null from jpox.properties with true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.storeManagerType value null from jpox.properties with rdbms
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.schema.validateColumns value null from jpox.properties with false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.schema.validateConstraints value null from jpox.properties with false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: Overriding datanucleus.schema.validateTables value null from jpox.properties with false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.rdbms.useLegacyNativeValueStrategy = true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.schema.validateConstraints = false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.option.ConnectionUserName = postgres
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.storeManagerType = rdbms
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.option.ConnectionDriverName = org.postgresql.Driver
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.cache.level2.type = none
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.option.NonTransactionalRead = true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.option.ConnectionURL = jdbc:postgresql://lighthouse-outpost-dev-hivemetastoredb.cm25znb924dp.ap-northeast-1.rds.amazonaws.com:5432/hivemetastoredb?allowPublicKeyRetrieval=true&useSSL=false&serverTimezone=UTC
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.connectionPool.maxPoolSize = 10
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.rdbms.initializeColumnInfo = NONE
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.connectionPoolingType = HikariCP
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.schema.validateColumns = false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.transactionIsolation = read-committed
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.cache.level2 = false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.schema.autoCreateAll = false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.identifierFactory = datanucleus1
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.option.Multithreaded = true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.plugin.pluginRegistryBundleCheck = LOG
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.PersistenceManagerFactoryClass = org.datanucleus.api.jdo.JDOPersistenceManagerFactory
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: javax.jdo.option.DetachAllOnCommit = true
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.schema.validateTables = false
2023-05-08T01:03:01,166 DEBUG [pool-6-thread-16] metastore.ObjectStore: datanucleus.autoStartMechanismMode = ignored
2023-05-08T01:03:01,167 DEBUG [pool-6-thread-16] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@6ff4a10a, with PersistenceManager: null will be shutdown
2023-05-08T01:03:01,167 INFO [pool-6-thread-16] metastore.ObjectStore: ObjectStore, initialize called
2023-05-08T01:03:01,181 DEBUG [pool-6-thread-16] pool.PoolBase: HikariPool-2 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@4cf46574
2023-05-08T01:03:01,182 DEBUG [pool-6-thread-16] pool.PoolBase: HikariPool-2 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@4cf46574
2023-05-08T01:03:01,185 DEBUG [pool-6-thread-16] pool.PoolBase: HikariPool-2 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@4cf46574
2023-05-08T01:03:01,193 DEBUG [pool-6-thread-16] pool.PoolBase: HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@5fdcc63f
2023-05-08T01:03:01,193 INFO [pool-6-thread-16] metastore.MetaStoreDirectSql: Using direct SQL, underlying DB is POSTGRES
2023-05-08T01:03:01,193 DEBUG [pool-6-thread-16] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@6ff4a10a, with PersistenceManager: org.datanucleus.api.jdo.JDOPersistenceManager@3d2269e5 created in the thread with id: 41
2023-05-08T01:03:01,193 INFO [pool-6-thread-16] metastore.ObjectStore: Initialized ObjectStore
2023-05-08T01:03:01,193 DEBUG [pool-6-thread-16] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.start(ObjectStore.java:3639)
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.run(ObjectStore.java:3609)
org.apache.hadoop.hive.metastore.ObjectStore.getDatabaseInternal(ObjectStore.java:1019)
2023-05-08T01:03:01,197 DEBUG [pool-6-thread-16] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.commit(ObjectStore.java:3727)
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.run(ObjectStore.java:3624)
org.apache.hadoop.hive.metastore.ObjectStore.getDatabaseInternal(ObjectStore.java:1019)
2023-05-08T01:03:01,198 DEBUG [pool-6-thread-16] pool.PoolBase: HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@5fdcc63f
2023-05-08T01:03:01,198 DEBUG [pool-6-thread-16] metastore.ObjectStore: db details for db test retrieved using SQL in 5.000295ms
2023-05-08T01:03:01,198 WARN [pool-6-thread-16] metastore.ObjectStore: Failed to get database hive.test, returning NoSuchObjectException
2023-05-08T01:03:01,198 DEBUG [pool-6-thread-16] metastore.ObjectStore: Fetching catalog hive
2023-05-08T01:03:01,198 DEBUG [pool-6-thread-16] metastore.ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore.getMCatalog(ObjectStore.java:905)
org.apache.hadoop.hive.metastore.ObjectStore.getCatalog(ObjectStore.java:852)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-05-08T01:03:01,205 DEBUG [pool-6-thread-16] metastore.ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore.getMCatalog(ObjectStore.java:912)
org.apache.hadoop.hive.metastore.ObjectStore.getCatalog(ObjectStore.java:852)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-05-08T01:03:01,207 DEBUG [pool-6-thread-16] pool.PoolBase: HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@5fdcc63f
2023-05-08T01:03:01,213 DEBUG [pool-6-thread-16] s3a.S3AFileSystem: Getting path status for s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test (test); needEmptyDirectory=false
2023-05-08T01:03:01,213 DEBUG [pool-6-thread-16] s3a.S3AFileSystem: S3GetFileStatus s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test
2023-05-08T01:03:01,214 DEBUG [pool-6-thread-16] s3a.S3AFileSystem: HEAD test with change tracker null
2023-05-08T01:03:01,214 DEBUG [pool-6-thread-16] impl.LoggingAuditor: [41] b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006 Executing op_get_file_status with {action_http_head_request 'test' size=0, mutating=false}; https://audit.example.org/hadoop/1/op_get_file_status/b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006/?op=op_get_file_status&p1=test&pr=root&ps=0f883630-16e0-4932-9e7c-0e2773844e43&id=b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006&t0=41&fs=b4ee24d8-4ad8-44b5-9b20-58a10042c35b&t1=41&ts=1683507781213
2023-05-08T01:03:01,214 DEBUG [pool-6-thread-16] amazonaws.request: Sending Request: HEAD https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com /test
2023-05-08T01:03:01,215 DEBUG [pool-6-thread-16] auth.AWS4Signer: AWS4 Canonical Request: '"HEAD
/test
amz-sdk-invocation-id:1c01a419-d833-12fe-4002-08fb9e22a3cc
amz-sdk-request:ttl=20230508T010621Z;attempt=1;max=21
amz-sdk-retry:0/0/500
content-type:application/octet-stream
host:ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com
referer:https://audit.example.org/hadoop/1/op_get_file_status/b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006/?op=op_get_file_status&p1=test&pr=root&ps=0f883630-16e0-4932-9e7c-0e2773844e43&id=b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006&t0=41&fs=b4ee24d8-4ad8-44b5-9b20-58a10042c35b&t1=41&ts=1683507781213
user-agent:Hadoop 3.3.5, aws-sdk-java/1.12.462 Linux/5.10.178-162.673.amzn2.x86_64 OpenJDK_64-Bit_Server_VM/11.0.19+7 java/11.0.19 kotlin/1.4.10 vendor/Eclipse_Adoptium cfg/retry-mode/legacy
x-amz-content-sha256:UNSIGNED-PAYLOAD
x-amz-date:20230508T010301Z
amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;content-type;host;referer;user-agent;x-amz-content-sha256;x-amz-date
UNSIGNED-PAYLOAD"
2023-05-08T01:03:01,215 DEBUG [pool-6-thread-16] auth.AWS4Signer: AWS4 String to Sign: '"AWS4-HMAC-SHA256
20230508T010301Z
20230508/ap-northeast-1/s3/aws4_request
d5140f051b3dffc7615fb2fda81ca3825be5109bc7c968c75fec73104b47f761"
2023-05-08T01:03:01,216 DEBUG [pool-6-thread-16] protocol.RequestAddCookies: CookieSpec selected: default
2023-05-08T01:03:01,216 DEBUG [pool-6-thread-16] protocol.RequestAuthCache: Auth cache not set in the context
2023-05-08T01:03:01,216 DEBUG [pool-6-thread-16] conn.PoolingHttpClientConnectionManager: Connection request: [route: {s}->https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com:443][total available: 1; route allocated: 1 of 96; total allocated: 1 of 96]
2023-05-08T01:03:01,229 DEBUG [pool-6-thread-16] http.wire: http-outgoing-0 << "end of stream"
2023-05-08T01:03:01,229 DEBUG [pool-6-thread-16] conn.DefaultManagedHttpClientConnection: http-outgoing-0: Close connection
2023-05-08T01:03:01,230 DEBUG [pool-6-thread-16] conn.PoolingHttpClientConnectionManager: Connection leased: [id: 1][route: {s}->https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com:443][total available: 0; route allocated: 1 of 96; total allocated: 1 of 96]
2023-05-08T01:03:01,230 DEBUG [pool-6-thread-16] execchain.MainClientExec: Opening connection {s}->https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com:443
2023-05-08T01:03:01,275 DEBUG [pool-6-thread-16] conn.DefaultHttpClientConnectionOperator: Connecting to ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com/10.0.200.127:443
2023-05-08T01:03:01,275 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: Connecting socket to ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com/10.0.200.127:443 with timeout 5000
2023-05-08T01:03:01,276 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: Enabled protocols: [TLSv1.3, TLSv1.2]
2023-05-08T01:03:01,277 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: Enabled cipher suites:[TLS_AES_256_GCM_SHA384, TLS_AES_128_GCM_SHA256, TLS_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
2023-05-08T01:03:01,277 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: Starting handshake
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: Secure session established
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: negotiated protocol: TLSv1.2
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: negotiated cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: peer principal: CN=*.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: peer alternative names: [*.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com]
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] ssl.SSLConnectionSocketFactory: issuer principal: CN=Amazon RSA 2048 M01, O=Amazon, C=US
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] conn.DefaultHttpClientConnectionOperator: Connection established 10.0.201.67:48674<->10.0.200.127:443
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] conn.DefaultManagedHttpClientConnection: http-outgoing-1: set socket timeout to 200000
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] execchain.MainClientExec: Executing request HEAD /test HTTP/1.1
2023-05-08T01:03:01,292 DEBUG [pool-6-thread-16] execchain.MainClientExec: Proxy auth state: UNCHALLENGED
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> HEAD /test HTTP/1.1
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> Host: ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> amz-sdk-invocation-id: 1c01a419-d833-12fe-4002-08fb9e22a3cc
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> amz-sdk-request: ttl=20230508T010621Z;attempt=1;max=21
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> amz-sdk-retry: 0/0/500
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> Authorization: AWS4-HMAC-SHA256 Credential=AKIAYR27EH6MARMG5SZK/20230508/ap-northeast-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;content-type;host;referer;user-agent;x-amz-content-sha256;x-amz-date, Signature=f53897cc679d33dd9055d1f3a7a7124b3658c1bcd1d97fc76dca74d5a842876a
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> Content-Type: application/octet-stream
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> Referer: https://audit.example.org/hadoop/1/op_get_file_status/b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006/?op=op_get_file_status&p1=test&pr=root&ps=0f883630-16e0-4932-9e7c-0e2773844e43&id=b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006&t0=41&fs=b4ee24d8-4ad8-44b5-9b20-58a10042c35b&t1=41&ts=1683507781213
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> User-Agent: Hadoop 3.3.5, aws-sdk-java/1.12.462 Linux/5.10.178-162.673.amzn2.x86_64 OpenJDK_64-Bit_Server_VM/11.0.19+7 java/11.0.19 kotlin/1.4.10 vendor/Eclipse_Adoptium cfg/retry-mode/legacy
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> x-amz-content-sha256: UNSIGNED-PAYLOAD
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> X-Amz-Date: 20230508T010301Z
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 >> Connection: Keep-Alive
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "HEAD /test HTTP/1.1[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "Host: ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "amz-sdk-invocation-id: 1c01a419-d833-12fe-4002-08fb9e22a3cc[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "amz-sdk-request: ttl=20230508T010621Z;attempt=1;max=21[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "amz-sdk-retry: 0/0/500[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "Authorization: AWS4-HMAC-SHA256 Credential=AKIAYR27EH6MARMG5SZK/20230508/ap-northeast-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;content-type;host;referer;user-agent;x-amz-content-sha256;x-amz-date, Signature=f53897cc679d33dd9055d1f3a7a7124b3658c1bcd1d97fc76dca74d5a842876a[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "Content-Type: application/octet-stream[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "Referer: https://audit.example.org/hadoop/1/op_get_file_status/b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006/?op=op_get_file_status&p1=test&pr=root&ps=0f883630-16e0-4932-9e7c-0e2773844e43&id=b4ee24d8-4ad8-44b5-9b20-58a10042c35b-00000006&t0=41&fs=b4ee24d8-4ad8-44b5-9b20-58a10042c35b&t1=41&ts=1683507781213[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "User-Agent: Hadoop 3.3.5, aws-sdk-java/1.12.462 Linux/5.10.178-162.673.amzn2.x86_64 OpenJDK_64-Bit_Server_VM/11.0.19+7 java/11.0.19 kotlin/1.4.10 vendor/Eclipse_Adoptium cfg/retry-mode/legacy[\r][\n]"
2023-05-08T01:03:01,293 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "x-amz-content-sha256: UNSIGNED-PAYLOAD[\r][\n]"
2023-05-08T01:03:01,294 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "X-Amz-Date: 20230508T010301Z[\r][\n]"
2023-05-08T01:03:01,294 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "Connection: Keep-Alive[\r][\n]"
2023-05-08T01:03:01,294 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 >> "[\r][\n]"
2023-05-08T01:03:01,569 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "HTTP/1.1 400 Bad Request[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "Content-Type: application/xml[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "Server: AmazonS3[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "x-amz-id-2: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "x-amz-request-id: DB32B0B6EAF41D8B[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "Date: Mon, 08 May 2023 01:03:01 GMT[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.wire: http-outgoing-1 << "[\r][\n]"
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 << HTTP/1.1 400 Bad Request
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 << Content-Type: application/xml
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 << Server: AmazonS3
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 << x-amz-id-2: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 << x-amz-request-id: DB32B0B6EAF41D8B
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] http.headers: http-outgoing-1 << Date: Mon, 08 May 2023 01:03:01 GMT
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] execchain.MainClientExec: Connection can be kept alive for 60000 MILLISECONDS
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] conn.PoolingHttpClientConnectionManager: Connection [id: 1][route: {s}->https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com:443] can be kept alive for 60.0 seconds
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] conn.DefaultManagedHttpClientConnection: http-outgoing-1: set socket timeout to 0
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] conn.PoolingHttpClientConnectionManager: Connection released: [id: 1][route: {s}->https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com:443][total available: 1; route allocated: 1 of 96; total allocated: 1 of 96]
2023-05-08T01:03:01,570 DEBUG [pool-6-thread-16] retry.ClockSkewAdjuster: Reported server date (from 'Date' header): Mon, 08 May 2023 01:03:01 GMT
2023-05-08T01:03:01,571 DEBUG [pool-6-thread-16] amazonaws.request: Received error response: com.amazonaws.services.s3.model.AmazonS3Exception: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null), S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr
2023-05-08T01:03:01,571 DEBUG [pool-6-thread-16] amazonaws.latency: ServiceName=[Amazon S3], AWSErrorCode=[400 Bad Request], StatusCode=[400], ServiceEndpoint=[https://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3.op-01427051a3dc18b69.s3-outposts.ap-northeast-1.amazonaws.com], Exception=[com.amazonaws.services.s3.model.AmazonS3Exception: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null), S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr], RequestType=[GetObjectMetadataRequest], AWSRequestID=[DB32B0B6EAF41D8B], HttpClientPoolPendingCount=0, RetryCapacityConsumed=0, HttpClientPoolAvailableCount=1, RequestCount=1, Exception=1, HttpClientPoolLeasedCount=0, ClientExecuteTime=[357.011], HttpClientSendRequestTime=[1.446], HttpRequestTime=[354.943], ApiCallLatency=[356.573], RequestSigningTime=[0.588], CredentialsRequestTime=[0.009, 0.005], HttpClientReceiveResponseTime=[276.226],
2023-05-08T01:03:01,572 ERROR [pool-6-thread-16] utils.MetaStoreUtils: Got exception: org.apache.hadoop.fs.s3a.AWSBadRequestException getFileStatus on s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test: com.amazonaws.services.s3.model.AmazonS3Exception: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null), S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr:400 Bad Request: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null)
org.apache.hadoop.fs.s3a.AWSBadRequestException: getFileStatus on s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test: com.amazonaws.services.s3.model.AmazonS3Exception: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null), S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr:400 Bad Request: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null)
at org.apache.hadoop.fs.s3a.S3AUtils.translateException(S3AUtils.java:240) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AUtils.translateException(S3AUtils.java:171) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.s3GetFileStatus(S3AFileSystem.java:3645) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.innerGetFileStatus(S3AFileSystem.java:3551) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.lambda$getFileStatus$24(S3AFileSystem.java:3528) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.statistics.impl.IOStatisticsBinding.invokeTrackingDuration(IOStatisticsBinding.java:547) ~[hadoop-common-3.3.5.jar:?]
at org.apache.hadoop.fs.statistics.impl.IOStatisticsBinding.lambda$trackDurationOfOperation$5(IOStatisticsBinding.java:528) ~[hadoop-common-3.3.5.jar:?]
at org.apache.hadoop.fs.statistics.impl.IOStatisticsBinding.trackDuration(IOStatisticsBinding.java:449) ~[hadoop-common-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.trackDurationAndSpan(S3AFileSystem.java:2401) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.trackDurationAndSpan(S3AFileSystem.java:2420) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.getFileStatus(S3AFileSystem.java:3526) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.hive.metastore.Warehouse.isDir(Warehouse.java:661) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database_core(HiveMetaStore.java:1263) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database(HiveMetaStore.java:1327) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:?]
at java.lang.reflect.Method.invoke(Unknown Source) ~[?:?]
at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at com.sun.proxy.$Proxy33.create_database(Unknown Source) [?:?]
at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:14396) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:14380) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39) [libthrift-0.9.3.jar:0.9.3]
at org.apache.hadoop.hive.metastore.TUGIBasedProcessor.process(TUGIBasedProcessor.java:104) [hive-standalone-metastore-3.1.3.jar:3.1.3]
at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286) [libthrift-0.9.3.jar:0.9.3]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]
at java.lang.Thread.run(Unknown Source) [?:?]
Caused by: com.amazonaws.services.s3.model.AmazonS3Exception: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleErrorResponse(AmazonHttpClient.java:1879) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleServiceErrorResponse(AmazonHttpClient.java:1418) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1387) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1157) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:814) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:781) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:755) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:715) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:697) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:561) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:541) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:5470) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:5417) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:1373) ~[aws-java-sdk-bundle-1.12.462.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.lambda$getObjectMetadata$11(S3AFileSystem.java:2571) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.Invoker.retryUntranslated(Invoker.java:468) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.Invoker.retryUntranslated(Invoker.java:431) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.getObjectMetadata(S3AFileSystem.java:2559) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.getObjectMetadata(S3AFileSystem.java:2539) ~[hadoop-aws-3.3.5.jar:?]
at org.apache.hadoop.fs.s3a.S3AFileSystem.s3GetFileStatus(S3AFileSystem.java:3623) ~[hadoop-aws-3.3.5.jar:?]
... 26 more
2023-05-08T01:03:01,575 ERROR [pool-6-thread-16] utils.MetaStoreUtils: Converting exception to MetaException
2023-05-08T01:03:01,575 DEBUG [pool-6-thread-16] metastore.ObjectStore: rolling back transaction: no open transactions: 0 at:
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-05-08T01:03:01,575 ERROR [pool-6-thread-16] metastore.RetryingHMSHandler: MetaException(message:Got exception: org.apache.hadoop.fs.s3a.AWSBadRequestException getFileStatus on s3a://ipass-datala-o01427051a3dc18b69nmaa8betpfvhubhf2siqapn10--op-s3/test: com.amazonaws.services.s3.model.AmazonS3Exception: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null), S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr:400 Bad Request: Bad Request (Service: Amazon S3; Status Code: 400; Error Code: 400 Bad Request; Request ID: DB32B0B6EAF41D8B; S3 Extended Request ID: ThQo1cfF7FbhDuvXpf6ysiE4FPrkOqB9JsVvGilZPblbNKKac/7j9OrawVs6dvbON5MRB9FFrwWSCbu3H+4uYFaJkkrSPVGr; Proxy: null))
at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils.logAndThrowMetaException(MetaStoreUtils.java:168)
at org.apache.hadoop.hive.metastore.Warehouse.isDir(Warehouse.java:668)
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database_core(HiveMetaStore.java:1263)
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database(HiveMetaStore.java:1327)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.base/java.lang.reflect.Method.invoke(Unknown Source)
at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
at com.sun.proxy.$Proxy33.create_database(Unknown Source)
at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:14396)
at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:14380)
at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
at org.apache.hadoop.hive.metastore.TUGIBasedProcessor.process(TUGIBasedProcessor.java:104)
at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
2023-05-08T01:03:01,575 DEBUG [pool-6-thread-16] metrics.PerfLogger: </PERFLOG method=create_database start=1683507781161 end=1683507781575 duration=414 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=16 retryCount=-1 error=true>
2023-05-08T01:03:01,576 INFO [pool-6-thread-16] metastore.HiveMetaStore: 16: Cleaning up thread local RawStore...
2023-05-08T01:03:01,576 INFO [pool-6-thread-16] HiveMetaStore.audit: ugi=root ip=10.0.201.237 cmd=Cleaning up thread local RawStore...
2023-05-08T01:03:01,576 DEBUG [pool-6-thread-16] metastore.ObjectStore: RawStore: org.apache.hadoop.hive.metastore.ObjectStore@6ff4a10a, with PersistenceManager: org.datanucleus.api.jdo.JDOPersistenceManager@3d2269e5 will be shutdown
2023-05-08T01:03:01,576 INFO [pool-6-thread-16] metastore.HiveMetaStore: 16: Done cleaning up thread local RawStore
2023-05-08T01:03:01,576 INFO [pool-6-thread-16] HiveMetaStore.audit: ugi=root ip=10.0.201.237 cmd=Done cleaning up thread local RawStore
```