yaooqinn commented on issue #1988:
URL:
https://github.com/apache/incubator-kyuubi/issues/1988#issuecomment-1056494126
```
12:38:24.039 SparkSQLSessionManager-exec-pool: Thread-1855 INFO
ExecuteStatement: Processing runner's
query[7c19e75e-f644-4a69-9e55-458e10d724d9]: RUNNING_STATE -> RUNNING_STATE,
statement:
create table table_1_test (
id int,
name string,
price double,
ts long
) using hudi
options (
primaryKey = 'id',
preCombineField = 'ts',
hoodie.bootstrap.index.class =
'org.apache.hudi.common.bootstrap.index.NoOpBootstrapIndex'
)
12:38:24.040 SparkSQLSessionManager-exec-pool: Thread-1855 DEBUG
ExecuteStatement: == Parsed Logical Plan ==
'CreateTableStatement [table_1_test], [StructField(id,IntegerType,true),
StructField(name,StringType,true), StructField(price,DoubleType,true),
StructField(ts,LongType,true)], hudi, [primaryKey=id, preCombineField=ts,
hoodie.bootstrap.index.class=org.apache.hudi.common.bootstrap.index.NoOpBootstrapIndex],
false, false
== Analyzed Logical Plan ==
CreateHoodieTableCommand `default`.`table_1_test`, false
== Optimized Logical Plan ==
CreateHoodieTableCommand `default`.`table_1_test`, false
== Physical Plan ==
Execute CreateHoodieTableCommand
+- CreateHoodieTableCommand `default`.`table_1_test`, false
12:38:24.040 SparkSQLSessionManager-exec-pool: Thread-1855 INFO
ExecuteStatement: Execute in full collect mode
12:38:24.043 SparkSQLSessionManager-exec-pool: Thread-1855 INFO
ExecuteStatement: Processing runner's
query[7c19e75e-f644-4a69-9e55-458e10d724d9]: RUNNING_STATE -> FINISHED_STATE,
statement:
create table table_1_test (
id int,
name string,
price double,
ts long
) using hudi
options (
primaryKey = 'id',
preCombineField = 'ts',
hoodie.bootstrap.index.class =
'org.apache.hudi.common.bootstrap.index.NoOpBootstrapIndex'
)
, time taken: 25.728 seconds
12:38:24.044 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: writing data length: 79
12:38:24.044 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: CLIENT: reading data length: 79
12:38:24.044 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
InPlaceUpdateStream$EventNotifier: progress bar is complete
12:38:24.044 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: writing data length: 102
12:38:24.044 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: SERVER: reading data length: 102
12:38:24.044 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
SparkTBinaryFrontendService:
TGetResultSetMetadataReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:7C
19 E7 5E F6 44 4A 69 9E 55 45 8E 10 D7 24 D9, secret:1A D2 6A 34 96 65 45 45
BC DB 52 5F 03 31 E7 DB), operationType:EXECUTE_STATEMENT, hasResultSet:true))
12:38:24.045 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.045 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: writing data length: 125
12:38:24.045 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: CLIENT: reading data length: 125
12:38:24.045 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: writing data length: 88
12:38:24.045 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: SERVER: reading data length: 88
12:38:24.046 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
SparkTBinaryFrontendService:
TGetTablesReq(sessionHandle:TSessionHandle(sessionId:THandleIdentifier(guid:B1
14 99 AF 44 18 48 F4 BD ED 8E 53 9B 33 CE E1, secret:92 6D 4E 53 52 83 49 69 8E
1D 32 7F 99 9C 26 ED)), schemaName:%)
12:38:24.046 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO GetTables:
Processing runner's query[95399edb-c9dc-4a77-917e-8129ee1453b9]:
INITIALIZED_STATE -> RUNNING_STATE, statement: GET_TABLES [catalog: null,
schemaPattern: %, tablePattern: null, tableTypes: (VIEW, TABLE)]
12:38:24.047 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
<PERFLOG method=get_databases
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
12:38:24.048 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
HiveMetaStore: 11: get_databases: *
12:38:24.048 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO audit:
ugi=runner ip=unknown-ip-addr cmd=get_databases: *
12:38:24.048 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction created [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[]]
12:38:24.048 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction begun for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989 (optimistic=false)
12:38:24.048 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore.getAllDatabases(ObjectStore.java:864)
12:38:24.049 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Single-String with "select name from
org.apache.hadoop.hive.metastore.model.MDatabase"
12:38:24.049 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
Query "SELECT name FROM org.apache.hadoop.hive.metastore.model.MDatabase
FetchPlan [default]" of language "JDOQL" has been run before so reusing
existing generic compilation
12:38:24.049 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
Query "SELECT name FROM org.apache.hadoop.hive.metastore.model.MDatabase
FetchPlan [default]" of language "JDOQL" for datastore "rdbms-derby" has been
run before so reusing existing datastore compilation
12:38:24.050 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@528befd2
[conn=null, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true]"
opened with isolation level "read-committed" and auto-commit=false
12:38:24.050 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Running enlist operation on resource:
org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@4ea20ebd,
error code TMNOFLAGS and transaction: [DataNucleus Transaction, ID=Xid=�,
enlisted resources=[]]
12:38:24.050 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@528befd2
[conn=com.jolbox.bonecp.ConnectionHandle@b45fcbf, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" starting for transaction "Xid=�"
with flags "0"
12:38:24.050 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection added to the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@528befd2
[conn=com.jolbox.bonecp.ConnectionHandle@b45fcbf, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.050 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Executing "SELECT name FROM
org.apache.hadoop.hive.metastore.model.MDatabase" ...
12:38:24.053 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@63882c27"
12:38:24.053 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
SELECT A0."NAME" FROM DBS A0
12:38:24.054 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 1 ms
12:38:24.054 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Execution Time = 4 ms
12:38:24.054 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore.getAllDatabases(ObjectStore.java:869)
12:38:24.054 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committing for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989
12:38:24.054 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process started using ordered
flush - 0 enlisted objects
12:38:24.054 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process finished
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Performing check of objects for "persistence-by-reachability"
(commit) ...
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Completed check of objects for "persistence-by-reachability"
(commit).
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Committing [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@4ea20ebd]]
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@528befd2
[conn=com.jolbox.bonecp.ConnectionHandle@b45fcbf, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" committing for transaction "Xid=�"
with onePhase="true"
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@528befd2
[conn=com.jolbox.bonecp.ConnectionHandle@b45fcbf, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" closed
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection removed from the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@528befd2
[conn=com.jolbox.bonecp.ConnectionHandle@b45fcbf, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committed in 1 ms
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
</PERFLOG method=get_databases start=1646138304047 end=1646138304055 duration=8
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=11
retryCount=0 error=false>
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
<PERFLOG method=get_database
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
HiveMetaStore: 11: get_database: default
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO audit:
ugi=runner ip=unknown-ip-addr cmd=get_database: default
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction created [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[]]
12:38:24.055 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction begun for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989 (optimistic=false)
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.start(ObjectStore.java:2991)
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: SQL
Query : "select "DB_ID", "NAME", "DB_LOCATION_URI", "DESC", "OWNER_NAME",
"OWNER_TYPE" FROM "DBS" where "NAME" = ?"
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=null, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true]"
opened with isolation level "read-committed" and auto-commit=false
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Running enlist operation on resource:
org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@27322f7,
error code TMNOFLAGS and transaction: [DataNucleus Transaction, ID=Xid=�,
enlisted resources=[]]
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=com.jolbox.bonecp.ConnectionHandle@253cfb8, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" starting for transaction "Xid=�"
with flags "0"
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection added to the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=com.jolbox.bonecp.ConnectionHandle@253cfb8, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.056 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@68f6c974"
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
select "DB_ID", "NAME", "DB_LOCATION_URI", "DESC", "OWNER_NAME", "OWNER_TYPE"
FROM "DBS" where "NAME" = <'default'>
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 1 ms
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: SQL
Query : "select "PARAM_KEY", "PARAM_VALUE" FROM "DATABASE_PARAMS" WHERE
"DB_ID" = ? AND "PARAM_KEY" IS NOT NULL"
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection found in the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=com.jolbox.bonecp.ConnectionHandle@253cfb8, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@7be235bb"
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
select "PARAM_KEY", "PARAM_VALUE" FROM "DATABASE_PARAMS" WHERE "DB_ID" = <1>
AND "PARAM_KEY" IS NOT NULL
12:38:24.057 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 0 ms
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
MetaStoreDirectSql: getDatabase: directsql returning db default
locn[file:/home/runner/work/incubator-kyuubi/incubator-kyuubi/externals/kyuubi-spark-sql-engine/target/tmp/kyuubi-c3f3f5b3-a938-4248-b9fa-8fafb1da094c]
desc [Default Hive database] owner [public] ownertype [ROLE]
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.commit(ObjectStore.java:3084)
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committing for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process started using ordered
flush - 0 enlisted objects
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process finished
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Performing check of objects for "persistence-by-reachability"
(commit) ...
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Completed check of objects for "persistence-by-reachability"
(commit).
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Committing [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@27322f7]]
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=com.jolbox.bonecp.ConnectionHandle@253cfb8, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" committing for transaction "Xid=�"
with onePhase="true"
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=com.jolbox.bonecp.ConnectionHandle@253cfb8, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" closed
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection removed from the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@54fb14e5
[conn=com.jolbox.bonecp.ConnectionHandle@253cfb8, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committed in 0 ms
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: db details for db default retrieved using SQL in 2.904089ms
12:38:24.058 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
</PERFLOG method=get_database start=1646138304055 end=1646138304058 duration=3
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=11
retryCount=0 error=false>
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
<PERFLOG method=get_databases
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
HiveMetaStore: 11: get_databases: .*
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO audit:
ugi=runner ip=unknown-ip-addr cmd=get_databases: .*
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction created [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[]]
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction begun for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989 (optimistic=false)
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore.getDatabases(ObjectStore.java:834)
12:38:24.059 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Compiling "SELECT name FROM
org.apache.hadoop.hive.metastore.model.MDatabase WHERE (name.matches(:param1) )
ORDER BY name ascending"
12:38:24.060 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Compile Time = 1 ms
12:38:24.060 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
QueryCompilation:
[result:PrimaryExpression{name}]
[filter:InvokeExpression{[PrimaryExpression{name}].matches(ParameterExpression{param1})}]
[ordering:OrderExpression{PrimaryExpression{name} ascending}]
[symbols: this type=org.apache.hadoop.hive.metastore.model.MDatabase,
param1 type=unknown]
12:38:24.060 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Compiling "SELECT name FROM
org.apache.hadoop.hive.metastore.model.MDatabase WHERE (name.matches(:param1) )
ORDER BY name ascending" for datastore
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Compile Time for datastore = 1 ms
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
SELECT name FROM org.apache.hadoop.hive.metastore.model.MDatabase WHERE
(name.matches(:param1) ) ORDER BY name ascending Query compiled to datastore
query "SELECT A0."NAME",A0."NAME" AS NUCORDER0 FROM DBS A0 WHERE
LOWER(A0."NAME") LIKE '_%' ESCAPE '\' ORDER BY NUCORDER0"
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: Not
caching the datastore compilation since some parameters are evaluated during
the compilation and arent present in the final datastore-specific query
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@27fb115c
[conn=null, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true]"
opened with isolation level "read-committed" and auto-commit=false
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Running enlist operation on resource:
org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@11989dd4,
error code TMNOFLAGS and transaction: [DataNucleus Transaction, ID=Xid=�,
enlisted resources=[]]
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@27fb115c
[conn=com.jolbox.bonecp.ConnectionHandle@6dda166a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" starting for transaction "Xid=�"
with flags "0"
12:38:24.061 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection added to the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@27fb115c
[conn=com.jolbox.bonecp.ConnectionHandle@6dda166a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.062 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Executing "SELECT name FROM
org.apache.hadoop.hive.metastore.model.MDatabase WHERE (name.matches(:param1) )
ORDER BY name ascending" ...
12:38:24.066 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@262c6372"
12:38:24.066 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
SELECT A0."NAME",A0."NAME" AS NUCORDER0 FROM DBS A0 WHERE LOWER(A0."NAME") LIKE
'_%' ESCAPE '\' ORDER BY NUCORDER0
12:38:24.066 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 0 ms
12:38:24.067 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
IsolatedClientLoader: hive class:
org.apache.derby.iapi.types.DataValueFactoryImpl$1 -
jar:file:/home/runner/.m2/repository/org/apache/derby/derby/10.12.1.1/derby-10.12.1.1.jar!/org/apache/derby/iapi/types/DataValueFactoryImpl$1.class
12:38:24.068 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Execution Time = 6 ms
12:38:24.068 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore.getDatabases(ObjectStore.java:849)
12:38:24.068 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committing for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989
12:38:24.068 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process started using ordered
flush - 0 enlisted objects
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process finished
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Performing check of objects for "persistence-by-reachability"
(commit) ...
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Completed check of objects for "persistence-by-reachability"
(commit).
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Committing [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@11989dd4]]
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@27fb115c
[conn=com.jolbox.bonecp.ConnectionHandle@6dda166a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" committing for transaction "Xid=�"
with onePhase="true"
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@27fb115c
[conn=com.jolbox.bonecp.ConnectionHandle@6dda166a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" closed
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection removed from the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@27fb115c
[conn=com.jolbox.bonecp.ConnectionHandle@6dda166a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committed in 1 ms
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
</PERFLOG method=get_databases start=1646138304059 end=1646138304069
duration=10 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler
threadId=11 retryCount=0 error=false>
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
<PERFLOG method=get_database
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
HiveMetaStore: 11: get_database: default
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO audit:
ugi=runner ip=unknown-ip-addr cmd=get_database: default
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction created [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[]]
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction begun for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989 (optimistic=false)
12:38:24.069 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.start(ObjectStore.java:2991)
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: SQL
Query : "select "DB_ID", "NAME", "DB_LOCATION_URI", "DESC", "OWNER_NAME",
"OWNER_TYPE" FROM "DBS" where "NAME" = ?"
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=null, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true]"
opened with isolation level "read-committed" and auto-commit=false
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Running enlist operation on resource:
org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@484b6d9a,
error code TMNOFLAGS and transaction: [DataNucleus Transaction, ID=Xid=�,
enlisted resources=[]]
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=com.jolbox.bonecp.ConnectionHandle@39061e63, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" starting for transaction "Xid=�"
with flags "0"
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection added to the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=com.jolbox.bonecp.ConnectionHandle@39061e63, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@494958f4"
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
select "DB_ID", "NAME", "DB_LOCATION_URI", "DESC", "OWNER_NAME", "OWNER_TYPE"
FROM "DBS" where "NAME" = <'default'>
12:38:24.070 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 0 ms
12:38:24.071 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: SQL
Query : "select "PARAM_KEY", "PARAM_VALUE" FROM "DATABASE_PARAMS" WHERE
"DB_ID" = ? AND "PARAM_KEY" IS NOT NULL"
12:38:24.071 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection found in the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=com.jolbox.bonecp.ConnectionHandle@39061e63, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.071 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@6d7b9660"
12:38:24.071 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
select "PARAM_KEY", "PARAM_VALUE" FROM "DATABASE_PARAMS" WHERE "DB_ID" = <1>
AND "PARAM_KEY" IS NOT NULL
12:38:24.071 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 0 ms
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
MetaStoreDirectSql: getDatabase: directsql returning db default
locn[file:/home/runner/work/incubator-kyuubi/incubator-kyuubi/externals/kyuubi-spark-sql-engine/target/tmp/kyuubi-c3f3f5b3-a938-4248-b9fa-8fafb1da094c]
desc [Default Hive database] owner [public] ownertype [ROLE]
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.commit(ObjectStore.java:3084)
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committing for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process started using ordered
flush - 0 enlisted objects
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process finished
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Performing check of objects for "persistence-by-reachability"
(commit) ...
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Completed check of objects for "persistence-by-reachability"
(commit).
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Committing [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@484b6d9a]]
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=com.jolbox.bonecp.ConnectionHandle@39061e63, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" committing for transaction "Xid=�"
with onePhase="true"
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=com.jolbox.bonecp.ConnectionHandle@39061e63, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" closed
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection removed from the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1a90935f
[conn=com.jolbox.bonecp.ConnectionHandle@39061e63, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committed in 0 ms
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: db details for db default retrieved using SQL in 2.995989ms
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
</PERFLOG method=get_database start=1646138304069 end=1646138304072 duration=3
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=11
retryCount=0 error=false>
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
<PERFLOG method=get_database
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
12:38:24.072 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
HiveMetaStore: 11: get_database: default
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO audit:
ugi=runner ip=unknown-ip-addr cmd=get_database: default
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction created [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[]]
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction begun for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989 (optimistic=false)
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.start(ObjectStore.java:2991)
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: SQL
Query : "select "DB_ID", "NAME", "DB_LOCATION_URI", "DESC", "OWNER_NAME",
"OWNER_TYPE" FROM "DBS" where "NAME" = ?"
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=null, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true]"
opened with isolation level "read-committed" and auto-commit=false
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Running enlist operation on resource:
org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@689dcbac,
error code TMNOFLAGS and transaction: [DataNucleus Transaction, ID=Xid=�,
enlisted resources=[]]
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=com.jolbox.bonecp.ConnectionHandle@34eed07a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" starting for transaction "Xid=�"
with flags "0"
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection added to the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=com.jolbox.bonecp.ConnectionHandle@34eed07a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@4f9b95a9"
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
select "DB_ID", "NAME", "DB_LOCATION_URI", "DESC", "OWNER_NAME", "OWNER_TYPE"
FROM "DBS" where "NAME" = <'default'>
12:38:24.073 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 0 ms
12:38:24.074 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: SQL
Query : "select "PARAM_KEY", "PARAM_VALUE" FROM "DATABASE_PARAMS" WHERE
"DB_ID" = ? AND "PARAM_KEY" IS NOT NULL"
12:38:24.074 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection found in the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=com.jolbox.bonecp.ConnectionHandle@34eed07a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.074 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@7d25957"
12:38:24.074 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
select "PARAM_KEY", "PARAM_VALUE" FROM "DATABASE_PARAMS" WHERE "DB_ID" = <1>
AND "PARAM_KEY" IS NOT NULL
12:38:24.074 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 0 ms
12:38:24.074 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
MetaStoreDirectSql: getDatabase: directsql returning db default
locn[file:/home/runner/work/incubator-kyuubi/incubator-kyuubi/externals/kyuubi-spark-sql-engine/target/tmp/kyuubi-c3f3f5b3-a938-4248-b9fa-8fafb1da094c]
desc [Default Hive database] owner [public] ownertype [ROLE]
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.commit(ObjectStore.java:3084)
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committing for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process started using ordered
flush - 0 enlisted objects
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process finished
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Performing check of objects for "persistence-by-reachability"
(commit) ...
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Completed check of objects for "persistence-by-reachability"
(commit).
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Committing [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@689dcbac]]
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=com.jolbox.bonecp.ConnectionHandle@34eed07a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" committing for transaction "Xid=�"
with onePhase="true"
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=com.jolbox.bonecp.ConnectionHandle@34eed07a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" closed
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection removed from the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@31dc20a1
[conn=com.jolbox.bonecp.ConnectionHandle@34eed07a, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committed in 0 ms
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: db details for db default retrieved using SQL in 2.63159ms
12:38:24.075 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
</PERFLOG method=get_database start=1646138304072 end=1646138304075 duration=3
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=11
retryCount=0 error=false>
12:38:24.076 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
<PERFLOG method=get_tables
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
12:38:24.076 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
HiveMetaStore: 11: get_tables: db=default pat=.*
12:38:24.076 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO audit:
ugi=runner ip=unknown-ip-addr cmd=get_tables: db=default pat=.*
12:38:24.076 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction created [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[]]
12:38:24.076 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction begun for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989 (optimistic=false)
12:38:24.076 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Open transaction: count = 1, isActive = true at:
org.apache.hadoop.hive.metastore.ObjectStore.getTables(ObjectStore.java:1179)
12:38:24.077 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
Query "SELECT tableName FROM org.apache.hadoop.hive.metastore.model.MTable
WHERE (database.name == :param1 ) && (tableName.matches(:param2) ) ORDER BY
tableName ascending FetchPlan [default]" of language "JDOQL" has been run
before so reusing existing generic compilation
12:38:24.077 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Compiling "SELECT tableName FROM
org.apache.hadoop.hive.metastore.model.MTable WHERE (database.name == :param1 )
&& (tableName.matches(:param2) ) ORDER BY tableName ascending" for datastore
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Compile Time for datastore = 1 ms
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
SELECT tableName FROM org.apache.hadoop.hive.metastore.model.MTable WHERE
(database.name == :param1 ) && (tableName.matches(:param2) ) ORDER BY
tableName ascending Query compiled to datastore query "SELECT
A0.TBL_NAME,A0.TBL_NAME AS NUCORDER0 FROM TBLS A0 LEFT OUTER JOIN DBS B0 ON
A0.DB_ID = B0.DB_ID WHERE B0."NAME" = ? AND LOWER(A0.TBL_NAME) LIKE '_%' ESCAPE
'\' ORDER BY NUCORDER0"
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query: Not
caching the datastore compilation since some parameters are evaluated during
the compilation and arent present in the final datastore-specific query
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1106a788
[conn=null, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true]"
opened with isolation level "read-committed" and auto-commit=false
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Running enlist operation on resource:
org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@157433cd,
error code TMNOFLAGS and transaction: [DataNucleus Transaction, ID=Xid=�,
enlisted resources=[]]
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1106a788
[conn=com.jolbox.bonecp.ConnectionHandle@22397c78, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" starting for transaction "Xid=�"
with flags "0"
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection added to the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1106a788
[conn=com.jolbox.bonecp.ConnectionHandle@22397c78, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Executing "SELECT tableName FROM
org.apache.hadoop.hive.metastore.model.MTable WHERE (database.name == :param1 )
&& (tableName.matches(:param2) ) ORDER BY tableName ascending" ...
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Datastore:
Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@4b7d8435"
12:38:24.078 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Native:
SELECT A0.TBL_NAME,A0.TBL_NAME AS NUCORDER0 FROM TBLS A0 LEFT OUTER JOIN DBS B0
ON A0.DB_ID = B0.DB_ID WHERE B0."NAME" = <'default'> AND LOWER(A0.TBL_NAME)
LIKE '_%' ESCAPE '\' ORDER BY NUCORDER0
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Retrieve:
Execution Time = 1 ms
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Query:
JDOQL Query : Execution Time = 1 ms
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
ObjectStore: Commit transaction: count = 0, isactive true at:
org.apache.hadoop.hive.metastore.ObjectStore.getTables(ObjectStore.java:1202)
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committing for ExecutionContext
org.datanucleus.ExecutionContextThreadedImpl@6bd2e989
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process started using ordered
flush - 0 enlisted objects
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: ExecutionContext.internalFlush() process finished
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Performing check of objects for "persistence-by-reachability"
(commit) ...
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Persistence: Completed check of objects for "persistence-by-reachability"
(commit).
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Committing [DataNucleus Transaction, ID=Xid=�, enlisted
resources=[org.datanucleus.store.rdbms.ConnectionFactoryImpl$EmulatedXAResource@157433cd]]
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1106a788
[conn=com.jolbox.bonecp.ConnectionHandle@22397c78, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" committing for transaction "Xid=�"
with onePhase="true"
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection(non-enlisted)
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1106a788
[conn=com.jolbox.bonecp.ConnectionHandle@22397c78, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" closed
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG Connection:
ManagedConnection removed from the pool :
"org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1106a788
[conn=com.jolbox.bonecp.ConnectionHandle@22397c78, commitOnRelease=false,
closeOnRelease=false, closeOnTxnEnd=true]" for
key="org.datanucleus.ExecutionContextThreadedImpl@6bd2e989" in
factory="ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@65a7a39b]"
12:38:24.079 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
Transaction: Transaction committed in 0 ms
12:38:24.080 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG PerfLogger:
</PERFLOG method=get_tables start=1646138304076 end=1646138304080 duration=4
from=org.apache.hadoop.hive.metastore.RetryingHMSHandler threadId=11
retryCount=0 error=false>
12:38:24.080 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO GetTables:
Processing runner's query[95399edb-c9dc-4a77-917e-8129ee1453b9]: RUNNING_STATE
-> FINISHED_STATE, statement: GET_TABLES [catalog: null, schemaPattern: %,
tablePattern: null, tableTypes: (VIEW, TABLE)], time taken: 0.034 seconds
12:38:24.080 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: writing data length: 102
12:38:24.080 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: CLIENT: reading data length: 102
12:38:24.080 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: writing data length: 102
12:38:24.080 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: SERVER: reading data length: 102
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
SparkTBinaryFrontendService:
TGetResultSetMetadataReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:95
39 9E DB C9 DC 4A 77 91 7E 81 29 EE 14 53 B9, secret:18 CD B0 B0 EC 42 43 FE
B6 7C 61 F4 94 6D 39 EB), operationType:GET_TABLES, hasResultSet:true))
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.081 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.082 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.082 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.082 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.082 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.082 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: writing data length: 1064
12:38:24.082 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: CLIENT: reading data length: 1064
12:38:24.083 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: writing data length: 112
12:38:24.083 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: SERVER: reading data length: 112
12:38:24.083 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
SparkTBinaryFrontendService:
TFetchResultsReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:95
39 9E DB C9 DC 4A 77 91 7E 81 29 EE 14 53 B9, secret:18 CD B0 B0 EC 42 43 FE
B6 7C 61 F4 94 6D 39 EB), operationType:GET_TABLES, hasResultSet:true),
orientation:FETCH_NEXT, maxRows:50)
12:38:24.083 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.083 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
CatalystSqlParser: Parsing command: string
12:38:24.084 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: writing data length: 275
12:38:24.085 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: CLIENT: reading data length: 275
12:38:24.088 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: writing data length: 96
12:38:24.088 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: SERVER: reading data length: 96
12:38:24.088 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
SparkTBinaryFrontendService:
TCloseOperationReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:7C
19 E7 5E F6 44 4A 69 9E 55 45 8E 10 D7 24 D9, secret:1A D2 6A 34 96 65 45 45
BC DB 52 5F 03 31 E7 DB), operationType:EXECUTE_STATEMENT, hasResultSet:true))
12:38:24.089 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: writing data length: 42
12:38:24.089 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: CLIENT: reading data length: 42
12:38:24.089 ScalaTest-main-running-SparkHudiOperationSuite DEBUG
TSaslTransport: writing data length: 151
12:38:24.089 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
TSaslTransport: SERVER: reading data length: 151
12:38:24.089 SparkTBinaryFrontendHandler-Pool: Thread-1854 DEBUG
SparkTBinaryFrontendService:
TExecuteStatementReq(sessionHandle:TSessionHandle(sessionId:THandleIdentifier(guid:B1
14 99 AF 44 18 48 F4 BD ED 8E 53 9B 33 CE E1, secret:92 6D 4E 53 52 83 49 69
8E 1D 32 7F 99 9C 26 ED)), statement:DROP TABLE IF EXISTS table_1_test,
confOverlay:{}, runAsync:true, queryTimeout:0)
12:38:24.089 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
OperationLog: Creating operation log file
/home/runner/work/incubator-kyuubi/incubator-kyuubi/externals/kyuubi-spark-sql-engine/target/work/target/engine_operation_logs/b11499af-4418-48f4-bded-8e539b33cee1/c6813f90-4304-4430-b6ad-1bd38e4d0d72
12:38:24.090 SparkTBinaryFrontendHandler-Pool: Thread-1854 INFO
ExecuteStatement: Processing runner's
query[c6813f90-4304-4430-b6ad-1bd38e4d0d72]: INITIALIZED_STATE ->
PENDING_STATE, statement: DROP TABLE IF EXISTS table_1_test
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
