aimenglin commented on issue #2685:
URL: https://github.com/apache/iceberg/issues/2685#issuecomment-858925332
@marton-bod Thanks for your patience and time for helping me debug.
1. Log
```
2021-06-09T23:25:37,850 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Compiling
command(queryId=shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1):
INSERT INTO TABLE hadoop_table_1
VALUES (7, "John", "Basketball", "Senior")
2021-06-09T23:25:37,876 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Concurrency mode is disabled, not creating a lock manager
2021-06-09T23:25:37,876 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Starting Semantic Analysis
2021-06-09T23:25:37,903 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Completed phase 1 of Semantic Analysis
2021-06-09T23:25:37,903 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for source tables
2021-06-09T23:25:37,903 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for subqueries
2021-06-09T23:25:37,903 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for destination tables
2021-06-09T23:25:37,928 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Completed getting MetaData in Semantic Analysis
2021-06-09T23:25:38,101 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Context: New scratch dir is
hdfs://shenme-cluster-3-m/tmp/hive/shenme_google_com/521d08fa-9fda-4ca3-8bab-3d0b60ddc6de/hive_2021-06-09_23-25-37_866_2611149539519878546-1
2021-06-09T23:25:38,619 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for source tables
2021-06-09T23:25:38,620 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for subqueries
2021-06-09T23:25:38,620 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for source tables
2021-06-09T23:25:38,631 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for subqueries
2021-06-09T23:25:38,631 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for destination tables
2021-06-09T23:25:40,604 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Launching Job 1 out of 1
2021-06-09T23:25:40,604 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Starting task [Stage-2:MAPRED] in serial mode
2021-06-09T23:25:40,686 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Context: New scratch dir is
hdfs://shenme-cluster-3-m/tmp/hive/shenme_google_com/521d08fa-9fda-4ca3-8bab-3d0b60ddc6de/hive_2021-06-09_23-25-37_866_2611149539519878546-1
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
tez.TezSessionPoolManager: The current user: shenme_google_com, session user:
shenme_google_com
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
tez.TezSessionPoolManager: Current queue name is null incoming queue name is
null
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
exec.Task: Subscribed to counters: [] for queryId:
shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1
2021-06-09T23:25:38,631 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Get metadata for destination tables
2021-06-09T23:25:38,696 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Context: New scratch dir is
hdfs://shenme-cluster-3-m/tmp/hive/shenme_google_com/521d08fa-9fda-4ca3-8bab-3d0b60ddc6de/hive_2021-06-09_23-25-37_866_2611149539519878546-1
2021-06-09T23:25:38,702 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:38,944 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:38,944 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hive.HiveIcebergSerDe: Using schema from existing table
{"type":"struct","fields":[{"id":1,"name":"id","required":true,"type":"int"},{"id":2,"name":"name","required":false,"type":"string"},{"id":3,"name":"major","required":false,"type":"string"},{"id":4,"name":"grade","required":false,"type":"string"}]}
2021-06-09T23:25:39,006 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:39,238 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:39,238 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hive.HiveIcebergSerDe: Using schema from existing table
{"type":"struct","fields":[{"id":1,"name":"id","required":true,"type":"int"},{"id":2,"name":"name","required":false,"type":"string"},{"id":3,"name":"major","required":false,"type":"string"},{"id":4,"name":"grade","required":false,"type":"string"}]}
2021-06-09T23:25:39,238 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:39,436 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:39,436 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hive.HiveIcebergSerDe: Using schema from existing table
{"type":"struct","fields":[{"id":1,"name":"id","required":true,"type":"int"},{"id":2,"name":"name","required":false,"type":"string"},{"id":3,"name":"major","required":false,"type":"string"},{"id":4,"name":"grade","required":false,"type":"string"}]}
2021-06-09T23:25:39,437 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
common.FileUtils: Creating directory if it doesn't exist:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1/.hive-staging_hive_2021-06-09_23-25-37_866_2611149539519878546-1
2021-06-09T23:25:39,518 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:39,707 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:39,800 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: CBO Succeeded; optimized logical plan.
2021-06-09T23:25:39,800 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ppd.OpProcFactory: Processing for FS(4)
2021-06-09T23:25:39,800 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ppd.OpProcFactory: Processing for SEL(3)
2021-06-09T23:25:39,800 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ppd.OpProcFactory: Processing for UDTF(2)
2021-06-09T23:25:39,800 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ppd.OpProcFactory: Processing for SEL(1)
2021-06-09T23:25:39,800 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ppd.OpProcFactory: Processing for TS(0)
2021-06-09T23:25:39,823 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.TezCompiler: Cycle free: true
2021-06-09T23:25:39,828 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
parse.CalcitePlanner: Completed plan generation
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Semantic Analysis Completed (retrial = false)
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:col1,
type:int, comment:null), FieldSchema(name:col2, type:string, comment:null),
FieldSchema(name:col3, type:string, comment:null), FieldSchema(name:col4,
type:string, comment:null)], properties:null)
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Completed compiling
command(queryId=shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1);
Time taken: 1.979 seconds
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
reexec.ReExecDriver: Execution #1 of query
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Concurrency mode is disabled, not creating a lock manager
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Executing
command(queryId=shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1):
INSERT INTO TABLE hadoop_table_1
VALUES (7, "John", "Basketball", "Senior")
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Query ID =
shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1
2021-06-09T23:25:39,829 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Total jobs = 1
2021-06-09T23:25:39,830 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Starting task [Stage-0:DDL] in serial mode
2021-06-09T23:25:39,852 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:40,093 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:40,093 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hive.HiveIcebergSerDe: Using schema from existing table
{"type":"struct","fields":[{"id":1,"name":"id","required":true,"type":"int"},{"id":2,"name":"name","required":false,"type":"string"},{"id":3,"name":"major","required":false,"type":"string"},{"id":4,"name":"grade","required":false,"type":"string"}]}
2021-06-09T23:25:40,094 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:40,327 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:40,327 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hive.HiveIcebergSerDe: Using schema from existing table
{"type":"struct","fields":[{"id":1,"name":"id","required":true,"type":"int"},{"id":2,"name":"name","required":false,"type":"string"},{"id":3,"name":"major","required":false,"type":"string"},{"id":4,"name":"grade","required":false,"type":"string"}]}
2021-06-09T23:25:40,328 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
mr.Catalogs: Catalog is not configured
2021-06-09T23:25:40,528 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hadoop.HadoopTables: Table location loaded:
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/test1
2021-06-09T23:25:40,528 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
hive.HiveIcebergSerDe: Using schema from existing table
{"type":"struct","fields":[{"id":1,"name":"id","required":true,"type":"int"},{"id":2,"name":"name","required":false,"type":"string"},{"id":3,"name":"major","required":false,"type":"string"},{"id":4,"name":"grade","required":false,"type":"string"}]}
2021-06-09T23:25:40,597 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Starting task [Stage-1:DDL] in serial mode
2021-06-09T23:25:40,604 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Launching Job 1 out of 1
2021-06-09T23:25:40,604 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Starting task [Stage-2:MAPRED] in serial mode
2021-06-09T23:25:40,686 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Context: New scratch dir is
hdfs://shenme-cluster-3-m/tmp/hive/shenme_google_com/521d08fa-9fda-4ca3-8bab-3d0b60ddc6de/hive_2021-06-09_23-25-37_866_2611149539519878546-1
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
tez.TezSessionPoolManager: The current user: shenme_google_com, session user:
shenme_google_com
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
tez.TezSessionPoolManager: Current queue name is null incoming queue name is
null
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
exec.Task: Subscribed to counters: [] for queryId:
shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1
2021-06-09T23:25:40,691 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
exec.Task: Session is already open
2021-06-09T23:25:40,694 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
tez.DagUtils: Resource modification time: 1623281030625 for
hdfs://shenme-cluster-3-m/tmp/hive/shenme_google_com/_tez_session_dir/521d08fa-9fda-4ca3-8bab-3d0b60ddc6de-resources/iceberg-hive-runtime.jar
2021-06-09T23:25:40,694 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
exec.Task: Dag name: INSERT INTO TABLE hadoop_table_1..."Senior") (Stage-2)
2021-06-09T23:25:40,698 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Context: New scratch dir is
hdfs://shenme-cluster-3-m/tmp/hive/shenme_google_com/521d08fa-9fda-4ca3-8bab-3d0b60ddc6de/hive_2021-06-09_23-25-37_866_2611149539519878546-1
2021-06-09T23:25:40,758 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
tez.DagUtils: Vertex has custom input? false
2021-06-09T23:25:40,759 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
exec.SerializationUtilities: Serializing MapWork using kryo
2021-06-09T23:25:40,789 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
exec.Utilities: Serialized plan (via RPC) - name: Map 1 size: 301.80KB
2021-06-09T23:25:40,891 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
client.TezClient: Submitting dag to TezSession,
sessionName=HIVE-521d08fa-9fda-4ca3-8bab-3d0b60ddc6de,
applicationId=application_1622522135523_0073, dagName=INSERT INTO TABLE
hadoop_table_1..."Senior") (Stage-2), callerContext={ context=HIVE,
callerType=HIVE_QUERY_ID,
callerId=shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1 }
2021-06-09T23:25:40,991 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
client.TezClient: Submitted dag to TezSession,
sessionName=HIVE-521d08fa-9fda-4ca3-8bab-3d0b60ddc6de,
applicationId=application_1622522135523_0073, dagId=dag_1622522135523_0073_2,
dagName=INSERT INTO TABLE hadoop_table_1..."Senior") (Stage-2)
2021-06-09T23:25:41,513 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
SessionState: Status: Running (Executing on YARN cluster with App id
application_1622522135523_0073)
2021-06-09T23:25:41,515 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
SessionState: Map 1: 0/1
2021-06-09T23:25:44,542 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
SessionState: Map 1: 0(+1)/1
2021-06-09T23:25:47,576 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
SessionState: Map 1: 0(+1)/1
2021-06-09T23:25:48,220 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
SessionState: Map 1: 1/1
2021-06-09T23:25:48,223 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Starting task [Stage-4:DDL] in serial mode
2021-06-09T23:25:48,224 INFO [521d08fa-9fda-4ca3-8bab-3d0b60ddc6de main]
ql.Driver: Completed executing
command(queryId=shenme_google_com_20210609232537_9d2ce449-4ebc-403b-8f74-8b08ba9f62d1);
Time taken: 8.395 seconds
```
2. Version
3. Explain Plan
```
hive> EXPLAIN INSERT INTO TABLE hadoop_table_1 VALUES (8, "Eve", "Zoology",
"Senior");
OK
Plan optimized by CBO.
Stage-0
Alter Table Operator:
old name:default.hadoop_table_1,type:drop props
Stage-1
Pre Insert operator:{"Pre-Insert task":{}}
Stage-4
Insert operator:{"Commit-Insert-Hook":{}}
Stage-2
Map 1
File Output Operator [FS_4]
table:{"name:":"default.hadoop_table_1"}
Select Operator [SEL_3] (rows=1 width=8)
Output:["_col0","_col1","_col2","_col3"]
UDTF Operator [UDTF_2] (rows=1 width=48)
function name:inline
Select Operator [SEL_1] (rows=1 width=48)
Output:["_col0"]
TableScan [TS_0] (rows=1 width=10)
_dummy_database@_dummy_table,_dummy_table,Tbl:COMPLETE,Col:COMPLETE
Time taken: 1.592 seconds, Fetched: 22 row(s)
```
4. Everytime when I insert the data, there'll be a _tmp file, but it's empty.
```
gsutil ls -la
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/_tmp.test1/
gsutil cat
gs://gcs-bucket-shenme-test-service-7f1dbd01-5cc9-4393-a54a-e9c2b9c9/hive-warehouse/_tmp.test1/#1623347746784286
```
--
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.
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
