---------- Forwarded message ---------
发件人： 张三 <zsan94...@gmail.com>
Date: 2024年6月19日周三 12:55
Subject: about hive4.0.0 error
To: <u...@hive.apache.org>
Dear Hive team,
I encountered an issue while using the latest version of Hive, 4.0.0. I am
not sure if this is a bug. The details are as follows: I am using Hadoop
version 3.3.6 and have set up a fully distributed cluster. The Hive version
is 4.0.0, with one master server and one client. Currently, I am connecting
to Hive via the Beeline client. When executing a join in Hive, I
encountered the following error:
```
0: jdbc:hive2://node1:10000> SELECT emp.emp_id, emp.emp_name, dept.dept_name
. . . . . . . . . . . . . .> FROM emp
. . . . . . . . . . . . . .> JOIN dept ON emp.dept_id = dept.dept_id;
INFO : Compiling
command(queryId=root_20240619122107_48e50dbd-9e12-4743-9652-f266165811bc):
SELECT emp.emp_id, emp.emp_name, dept.dept_name
FROM emp
JOIN dept ON emp.dept_id = dept.dept_id
INFO : No Stats for default@emp, Columns: emp_name, dept_id, emp_id
INFO : No Stats for default@dept, Columns: dept_name, dept_id
INFO : Semantic Analysis Completed (retrial = false)
INFO : Created Hive schema:
Schema(fieldSchemas:[FieldSchema(name:emp.emp_id, type:int, comment:null),
FieldSchema(name:emp.emp_name, type:strin
g, comment:null), FieldSchema(name:dept.dept_name, type:string,
comment:null)], properties:null)INFO : Completed compiling
command(queryId=root_20240619122107_48e50dbd-9e12-4743-9652-f266165811bc);
Time taken: 0.894 seconds
INFO : Concurrency mode is disabled, not creating a lock manager
INFO : Executing
command(queryId=root_20240619122107_48e50dbd-9e12-4743-9652-f266165811bc):
SELECT emp.emp_id, emp.emp_name, dept.dept_name
FROM emp
JOIN dept ON emp.dept_id = dept.dept_id
WARN : Hive-on-MR is deprecated in Hive 2 and may not be available in the
future versions. Consider using a different execution engine (i.e. tez
) or using Hive 1.X releases.INFO : Query ID =
root_20240619122107_48e50dbd-9e12-4743-9652-f266165811bc
INFO : Total jobs = 1
INFO : Starting task [Stage-4:MAPREDLOCAL] in serial mode
ERROR : Execution failed with exit status: 1
ERROR : Obtaining error information
ERROR :
Task failed!
Task ID:
Stage-4
Logs:
ERROR : /tmp/root/hive.log
ERROR : FAILED: Execution Error, return code 1 from
org.apache.hadoop.hive.ql.exec.mr.MapredLocalTask
INFO : Completed executing
command(queryId=root_20240619122107_48e50dbd-9e12-4743-9652-f266165811bc);
Time taken: 4.461 seconds
Error: Error while compiling statement: FAILED: Execution Error, return
code 1 from org.apache.hadoop.hive.ql.exec.mr.MapredLocalTask (state=08S0
1,code=1)
```
I checked the log on the Hive server at /tmp/root/hive.log and found the
following error information:
```
2024-06-19T11:22:56,454 INFO [NotificationEventPoll 0]
HiveMetaStore.audit: ugi=root ip=unknown-ip-addr cmd=get_config_value:
name=metast
ore.batch.retrieve.max defaultValue=50 2024-06-19T11:23:01,656 INFO
[Scheduled Query Poller] HiveMetaStore.audit: ugi=root ip=unknown-ip-addr
cmd=scheduled_query_poll
2024-06-19T11:23:56,375 INFO [NotificationEventPoll 0]
HiveMetaStore.audit: ugi=root ip=unknown-ip-addr cmd=get_config_value:
name=metast
ore.batch.retrieve.max defaultValue=50 2024-06-19T11:24:01,946 INFO
[Scheduled Query Poller] HiveMetaStore.audit: ugi=root ip=unknown-ip-addr
cmd=scheduled_query_poll
2024-06-19T11:24:56,373 INFO [NotificationEventPoll 0]
HiveMetaStore.audit: ugi=root ip=unknown-ip-addr cmd=get_config_value:
name=metast
ore.batch.retrieve.max defaultValue=50 2024-06-19T11:25:02,197 INFO
[Scheduled Query Poller] HiveMetaStore.audit: ugi=root ip=unknown-ip-addr
cmd=scheduled_query_poll
2024-06-19T11:25:56,376 INFO [NotificationEventPoll 0]
HiveMetaStore.audit: ugi=root ip=unknown-ip-addr cmd=get_config_value:
name=metast
ore.batch.retrieve.max defaultValue=50 2024-06-19T11:26:02,390 INFO
[Scheduled Query Poller] HiveMetaStore.audit: ugi=root ip=unknown-ip-addr
cmd=scheduled_query_poll
2024-06-19T11:26:56,373 INFO [NotificationEventPoll 0]
HiveMetaStore.audit: ugi=root ip=unknown-ip-addr cmd=get_config_value:
name=metast
ore.batch.retrieve.max defaultValue=50 2024-06-19T11:27:02,660 INFO
[Scheduled Query Poller] HiveMetaStore.audit: ugi=root ip=unknown-ip-addr
cmd=scheduled_query_poll
2024-06-19T11:27:48,645 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] session.HiveSessionImpl: executing
SELEC
T emp.emp_id, emp.emp_name, dept.dept_nameFROM emp
JOIN dept ON emp.dept_id = dept.dept_id
2024-06-19T11:27:48,654 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] operation.OperationManager: Adding
opera
tion: OperationHandle [opType=EXECUTE_STATEMENT,
getHandleIdentifier()=9c5817e6-131a-4e60-bfe3-faa066a61119] SessionHandle
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0]2024-06-19T11:27:48,654 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
common.LogUtils: Thread context registra
tion is done.2024-06-19T11:27:48,654 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
operation.SQLOperation: [opType=EXECUTE_
STATEMENT,
queryId=root_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba4ddd8,
startTime=1718767668646, sessionId=00b77a5e-7cec-4e10-a0ae-f94450a56ab0,
createTime=1718766580032, userName=root,
ipAddress=192.168.179.6]2024-06-19T11:27:48,655 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
reexec.ReExecDriver: Compile #1 of query
2024-06-19T11:27:48,655 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] ql.Driver: Compiling
command(queryId=roo
t_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba4ddd8): SELECT emp.emp_id,
emp.emp_name, dept.dept_nameFROM emp
JOIN dept ON emp.dept_id = dept.dept_id
2024-06-19T11:27:48,657 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] ql.QueryState: Query-level HMS cache
cre
ated for
root_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba4ddd82024-06-19T11:27:48,657
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] parse.CalcitePlanner: Starting Semantic
Analysis2024-06-19T11:27:48,657 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] parse.CalcitePlanner: Completed phase
1
of Semantic Analysis2024-06-19T11:27:48,657 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ource tables2024-06-19T11:27:48,658 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_table : tbl=hive.default.emp 2024-06-19T11:27:48,712
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: S
tarting translation for processor HMSClient-@node1 on list
12024-06-19T11:27:48,712 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] metastore.MetastoreDefaultTransformer:
T
able
emp,#bucket=-1,isBucketed:false,tableType=EXTERNAL_TABLE,tableCapabilities=null2024-06-19T11:27:48,713
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: T
ransformer return list of 12024-06-19T11:27:48,713 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_table : tbl=hive.default.dept 2024-06-19T11:27:48,749
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: S
tarting translation for processor HMSClient-@node1 on list
12024-06-19T11:27:48,749 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] metastore.MetastoreDefaultTransformer:
T
able
dept,#bucket=-1,isBucketed:false,tableType=EXTERNAL_TABLE,tableCapabilities=null2024-06-19T11:27:48,749
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: T
ransformer return list of 12024-06-19T11:27:48,749 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ubqueries2024-06-19T11:27:48,749 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for d
estination tables2024-06-19T11:27:48,749 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
ql.Context: New scratch dir is hdfs://my
cluster/tmp/hive/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:48,749
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] parse.CalcitePlanner: Completed getting
MetaData in Semantic Analysis2024-06-19T11:27:48,752 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_all_table_constraints : tbl=hive.default.emp
2024-06-19T11:27:48,792 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_all_table_constraints : tbl=hive.default.dept
2024-06-19T11:27:48,906 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] calcite.RelOptHiveTable: Calculating
col
umn statistics for default.emp, projIndxSet: [0, 1, 2], allowMissingStats:
true2024-06-19T11:27:48,907 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_table : tbl=hive.default.emp 2024-06-19T11:27:48,979
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: S
tarting translation for processor HMSClient-@node1 on list
12024-06-19T11:27:48,980 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] metastore.MetastoreDefaultTransformer:
T
able
emp,#bucket=-1,isBucketed:false,tableType=EXTERNAL_TABLE,tableCapabilities=null2024-06-19T11:27:48,980
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: T
ransformer return list of 12024-06-19T11:27:48,980 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_table_statistics_req: table=hive.default.emp
2024-06-19T11:27:49,010 WARN [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] calcite.RelOptHiveTable: No Stats for
de
fault@emp, Columns: emp_name, dept_id, emp_id2024-06-19T11:27:49,010 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
SessionState: No Stats for default@emp,
Columns: emp_name, dept_id, emp_id2024-06-19T11:27:49,011 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
calcite.RelOptHiveTable: Calculating col
umn statistics for default.dept, projIndxSet: [0, 1], allowMissingStats:
true2024-06-19T11:27:49,011 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_table : tbl=hive.default.dept 2024-06-19T11:27:49,080
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: S
tarting translation for processor HMSClient-@node1 on list
12024-06-19T11:27:49,080 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] metastore.MetastoreDefaultTransformer:
T
able
dept,#bucket=-1,isBucketed:false,tableType=EXTERNAL_TABLE,tableCapabilities=null2024-06-19T11:27:49,083
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] metastore.MetastoreDefaultTransformer: T
ransformer return list of 12024-06-19T11:27:49,084 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
HiveMetaStore.audit: ugi=root ip=unknow
n-ip-addr cmd=get_table_statistics_req: table=hive.default.dept
2024-06-19T11:27:49,121 WARN [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] calcite.RelOptHiveTable: No Stats for
de
fault@dept, Columns: dept_name, dept_id2024-06-19T11:27:49,121 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
SessionState: No Stats for default@dept,
Columns: dept_name, dept_id2024-06-19T11:27:49,221 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
common.FileUtils: Creating directory if
it doesn't exist:
hdfs://mycluster/tmp/hive/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-1/-mr-10001/.hive-staging_hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:49,215
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] parse.CalcitePlanner: Get metadata for s
ource tables2024-06-19T11:27:49,215 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ubqueries2024-06-19T11:27:49,215 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ource tables2024-06-19T11:27:49,215 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ubqueries2024-06-19T11:27:49,215 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for d
estination tables2024-06-19T11:27:49,215 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ource tables2024-06-19T11:27:49,216 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for s
ubqueries2024-06-19T11:27:49,216 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for d
estination tables2024-06-19T11:27:49,216 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Get metadata for d
estination tables2024-06-19T11:27:49,216 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
ql.Context: New scratch dir is hdfs://my
cluster/tmp/hive/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:49,301
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] parse.CalcitePlanner: CBO Succeeded; opt
imized logical plan.2024-06-19T11:27:49,305 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.ColumnPrunerProcFactory: JOIN
8 oldExprs: {0=[Column[VALUE._col0], Column[VALUE._col1],
Column[KEY.reducesinkkey0]], 1=[Column[KEY.reducesinkkey0],
Column[VALUE._col0]]}2024-06-19T11:27:49,305 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.ColumnPrunerProcFactory: JOIN
8 newExprs: {0=[Column[VALUE._col0], Column[VALUE._col1]],
1=[Column[VALUE._col0]]}2024-06-19T11:27:49,305 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.ColumnPrunerProcFactory: RS 6
oldColExprMap: {VALUE._col0=Column[_col0], VALUE._col1=Column[_col1],
KEY.reducesinkkey0=Column[_col2]}2024-06-19T11:27:49,305 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.ColumnPrunerProcFactory: RS 6
newColExprMap: {VALUE._col0=Column[_col0], VALUE._col1=Column[_col1],
KEY.reducesinkkey0=Column[_col2]}2024-06-19T11:27:49,305 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.ColumnPrunerProcFactory: RS 7
oldColExprMap: {VALUE._col0=Column[_col1],
KEY.reducesinkkey0=Column[_col0]}2024-06-19T11:27:49,306 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.ColumnPrunerProcFactory: RS 7
newColExprMap: {VALUE._col0=Column[_col1],
KEY.reducesinkkey0=Column[_col0]}2024-06-19T11:27:49,307 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
optimizer.BucketVersionPopulator: not co
nsidering bucketingVersion for: TS[0] because it has -1<2 buckets
2024-06-19T11:27:49,307 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] optimizer.BucketVersionPopulator: not
co
nsidering bucketingVersion for: TS[3] because it has -1<2 buckets
2024-06-19T11:27:49,308 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] optimizer.SortedDynPartitionOptimizer:
S
orted dynamic partitioning optimization kicked in..2024-06-19T11:27:49,348
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] exec.Utilities: Not using thread pool fo
r getContentSummary2024-06-19T11:27:49,371 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
ql.Context: New scratch dir is hdfs://my
cluster/tmp/hive/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:49,371
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] physical.LocalMapJoinProcFactory: Settin
g max memory usage to 0.9 for table sink not followed by group
by2024-06-19T11:27:49,372 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] physical.Vectorizer: Examining input
for
mat to see if vectorization is enabled.2024-06-19T11:27:49,372 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
physical.Vectorizer: Vectorization is en
abled for input format(s)
[org.apache.hadoop.mapred.TextInputFormat]2024-06-19T11:27:49,372 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
physical.Vectorizer: Validating and vect
orizing MapWork... (vectorizedVertexNum 0)2024-06-19T11:27:49,373 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
physical.Vectorizer: Map vectorization e
nabled: true2024-06-19T11:27:49,373 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
physical.Vectorizer: Map vectorized: tru
e2024-06-19T11:27:49,373 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] physical.Vectorizer: Map
vectorizedVerte
xNum: 02024-06-19T11:27:49,373 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] physical.Vectorizer: Map
enabledConditio
nsMet: [hive.vectorized.use.vector.serde.deserialize IS
true]2024-06-19T11:27:49,373 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] physical.Vectorizer: Map
inputFileFormat
ClassNameSet:
[org.apache.hadoop.mapred.TextInputFormat]2024-06-19T11:27:49,374 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
parse.CalcitePlanner: Completed plan gen
eration2024-06-19T11:27:49,374 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] ql.Driver: Semantic Analysis Completed
(
retrial = false)2024-06-19T11:27:49,374 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
ql.Driver: Created Hive schema: Schema(f
ieldSchemas:[FieldSchema(name:emp.emp_id, type:int, comment:null),
FieldSchema(name:emp.emp_name, type:string, comment:null),
FieldSchema(name:dept.dept_name, type:string, comment:null)],
properties:null)2024-06-19T11:27:49,375 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
exec.ListSinkOperator: Initializing Oper
ator: LIST_SINK[21]2024-06-19T11:27:49,375 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
metadata.Hive: Dumping metastore api cal
l timing information for : compilation phase2024-06-19T11:27:49,375 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
metadata.Hive: Total time spent in each
metastore function (ms): {getTableColumnStatistics_(String, String, List,
String)=213, isCompatibleWith_(Configuration)=1,
getAllTableConstraints_(AllTableConstraintsRequest)=100,
getTable_(GetTableRequest)=92, flushCache_()=0}2024-06-19T11:27:49,375
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] ql.Driver: Completed compiling command(q
ueryId=root_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba4ddd8); Time
taken: 0.72 seconds2024-06-19T11:27:49,375 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
common.LogUtils: Unregistered logging co
ntext.2024-06-19T11:27:49,377 INFO [HiveServer2-Background-Pool:
Thread-110] common.LogUtils: Thread context registration is done.
2024-06-19T11:27:49,377 INFO [HiveServer2-Background-Pool: Thread-110]
reexec.ReExecDriver: Execution #1 of query
2024-06-19T11:27:49,378 INFO [HiveServer2-Background-Pool: Thread-110]
ql.Driver: Concurrency mode is disabled, not creating a lock manager
2024-06-19T11:27:49,378 INFO [HiveServer2-Background-Pool: Thread-110]
ql.Driver: Executing command(queryId=root_20240619112748_9448d222-0018-4d
d7-ba8a-4c30eba4ddd8): SELECT emp.emp_id, emp.emp_name, dept.dept_nameFROM
emp
JOIN dept ON emp.dept_id = dept.dept_id
2024-06-19T11:27:49,378 WARN [HiveServer2-Background-Pool: Thread-110]
ql.Driver: Hive-on-MR is deprecated in Hive 2 and may not be available in
the future versions. Consider using a different execution engine (i.e.
tez) or using Hive 1.X releases.2024-06-19T11:27:49,385 INFO
[HiveServer2-Background-Pool: Thread-110] ql.Driver: Query ID =
root_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba
4ddd82024-06-19T11:27:49,385 INFO [HiveServer2-Background-Pool:
Thread-110] ql.Driver: Total jobs = 1
2024-06-19T11:27:49,386 INFO [HiveServer2-Background-Pool: Thread-110]
ql.Driver: Starting task [Stage-4:MAPREDLOCAL] in serial mode
2024-06-19T11:27:49,388 INFO [HiveServer2-Background-Pool: Thread-110]
mr.MapredLocalTask: Generating plan file file:/tmp/root/00b77a5e-7cec-4e1
0-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-6/-local-10006/plan.xml2024-06-19T11:27:49,389
INFO [HiveServer2-Background-Pool: Thread-110]
exec.SerializationUtilities: Serializing MapredLocalWork using kryo
2024-06-19T11:27:49,466 INFO [HiveServer2-Background-Pool: Thread-110]
mr.MapredLocalTask: Executing: /software/hadoop-3.3.6//bin/hadoop jar /so
ftware/hive-4.0.0/lib/hive-common-4.0.0.jar
org.apache.hadoop.hive.ql.exec.mr.ExecDriver -localtask -plan
file:/tmp/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-6/-local-10006/plan.xml
-jobconffile
file:/tmp/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-6/-local-10007/jobconf.xml2024-06-19T11:27:50,442
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: SLF4J: Class
path contai
ns multiple SLF4J bindings.2024-06-19T11:27:50,442 INFO
[HiveServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: SLF4J: Found binding in
[jar:file:/software/hive-4.0.0/lib/log4j-slf4j-impl-2.18.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]2024-06-19T11:27:50,442
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: SLF4J: Found
binding in
[jar:file:/software/hadoop-3.3.6/share/hadoop/common/lib/slf4j-reload4j-1.7.36.jar!/org/slf4j/impl/StaticLoggerBinder.class]2024-06-19T11:27:50,442
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: SLF4J: See
http://www.sl
f4j.org/codes.html#multiple_bindings for an
explanation.2024-06-19T11:27:50,637 INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: SLF4J: Actual
binding is
of type
[org.apache.logging.slf4j.Log4jLoggerFactory]2024-06-19T11:27:52,921 INFO
[main] conf.HiveConf: Found configuration file
file:/software/hive-4.0.0/conf/hive-site.xml
2024-06-19T11:27:52,951 INFO [main] common.LogUtils: Thread context
registration is done.
eServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: at
org.apache.hadoop.conf.Configuration.<init>(Configurat
ion.java:843)2024-06-19T11:27:54,865 INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: at
org.apache.had
oop.mapred.JobConf.<init>(JobConf.java:458)2024-06-19T11:27:54,865 INFO
[HiveServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: at org.apache.had
oop.mapred.JobConf.<init>(JobConf.java:475)2024-06-19T11:27:54,865 INFO
[HiveServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: at org.apache.had
oop.hive.ql.exec.mr.MapredLocalTask.initialize(MapredLocalTask.java:136)2024-06-19T11:27:54,865
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: at
org.apache.had
oop.hive.ql.exec.mr.ExecDriver.main(ExecDriver.java:766)2024-06-19T11:27:54,865
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: at
sun.reflect.Na
tiveMethodAccessorImpl.invoke0(Native Method)2024-06-19T11:27:54,865 INFO
[HiveServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: at sun.reflect.Na
tiveMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)2024-06-19T11:27:54,865
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: at
sun.reflect.De
legatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)2024-06-19T11:27:54,865
INFO [HiveServer2-Background-Pool:
Thread-110-LocalTask-MAPREDLOCAL-stderr] mr.MapredLocalTask: at
java.lang.refl
ect.Method.invoke(Method.java:498)2024-06-19T11:27:54,865 INFO
[HiveServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: at org.apache.had
oop.util.RunJar.run(RunJar.java:328)2024-06-19T11:27:54,865 INFO
[HiveServer2-Background-Pool: Thread-110-LocalTask-MAPREDLOCAL-stderr]
mr.MapredLocalTask: at org.apache.had
oop.util.RunJar.main(RunJar.java:241)2024-06-19T11:27:54,945 ERROR
[HiveServer2-Background-Pool: Thread-110] exec.Task: Execution failed with
exit status: 1
2024-06-19T11:27:54,945 ERROR [HiveServer2-Background-Pool: Thread-110]
exec.Task: Obtaining error information
2024-06-19T11:27:54,945 ERROR [HiveServer2-Background-Pool: Thread-110]
exec.Task:
Task failed!
Task ID:
Stage-4
Logs:
2024-06-19T11:27:54,945 ERROR [HiveServer2-Background-Pool: Thread-110]
exec.Task: /tmp/root/hive.log
2024-06-19T11:27:54,945 ERROR [HiveServer2-Background-Pool: Thread-110]
mr.MapredLocalTask: Execution failed with exit status: 1
2024-06-19T11:27:54,945 INFO [HiveServer2-Background-Pool: Thread-110]
reexec.ReOptimizePlugin: ReOptimization: retryPossible: false
2024-06-19T11:27:54,945 INFO [HiveServer2-Background-Pool: Thread-110]
reexec.ReExecuteLostAMQueryPlugin: Exception is not a TezRuntimeException
, no need to check further with
ReExecuteLostAMQueryPlugin2024-06-19T11:27:54,945 ERROR
[HiveServer2-Background-Pool: Thread-110] ql.Driver: FAILED: Execution
Error, return code 1 from org.apache.hadoop.
hive.ql.exec.mr.MapredLocalTask2024-06-19T11:27:54,946 INFO
[HiveServer2-Background-Pool: Thread-110] metadata.Hive: Dumping metastore
api call timing information for : execut
ion phase2024-06-19T11:27:54,946 INFO [HiveServer2-Background-Pool:
Thread-110] metadata.Hive: Total time spent in each metastore function
(ms): {}
2024-06-19T11:27:54,946 INFO [HiveServer2-Background-Pool: Thread-110]
ql.Driver: Completed executing command(queryId=root_20240619112748_9448d2
22-0018-4dd7-ba8a-4c30eba4ddd8); Time taken: 5.567
seconds2024-06-19T11:27:54,946 INFO [HiveServer2-Background-Pool:
Thread-110] reexec.ReExecDriver: Re-execution decision is made according
to: executio
nIndex: 1, maxExecutions: 2, shouldReExecute: false2024-06-19T11:27:54,947
INFO [HiveServer2-Background-Pool: Thread-110] common.LogUtils:
Unregistered logging context.
2024-06-19T11:27:54,947 ERROR [HiveServer2-Background-Pool: Thread-110]
operation.SQLOperation: Error running hive query
org.apache.hive.service.cli.HiveSQLException: Error while compiling
statement: FAILED: Execution Error, return code 1 from
org.apache.hadoop.hive
.ql.exec.mr.MapredLocalTask at
org.apache.hive.service.cli.operation.Operation.toSQLException(Operation.java:376)
~[hive-service-4.0.0.jar:4.0.0]
at
org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:249)
~[hive-service-4.0.0.jar:4.0.0]
at
org.apache.hive.service.cli.operation.SQLOperation.access$500(SQLOperation.java:90)
~[hive-service-4.0.0.jar:4.0.0]
at
org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork$1.run(SQLOperation.java:336)
~[hive-service-4.0.0.jar:4.0.0]
at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_181]
at javax.security.auth.Subject.doAs(Subject.java:422) ~[?:1.8.0_181]
at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1899)
~[hadoop-common-3.3.6.jar:?]
at
org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork.run(SQLOperation.java:356)
~[hive-service-4.0.0.jar:4.0.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
~[?:1.8.0_181]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_181]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
~[?:1.8.0_181]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
~[?:1.8.0_181]
at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_181]
2024-06-19T11:27:54,960 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] operation.OperationManager: Closing
oper
ation: OperationHandle [opType=EXECUTE_STATEMENT,
getHandleIdentifier()=9c5817e6-131a-4e60-bfe3-faa066a61119]2024-06-19T11:27:54,960
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] operation.OperationManager: Removed quer
yId: root_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba4ddd8 corresponding
to operation: OperationHandle [opType=EXECUTE_STATEMENT,
getHandleIdentifier()=9c5817e6-131a-4e60-bfe3-faa066a61119] with tag:
null2024-06-19T11:27:54,961 INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0
HiveServer2-Handler-Pool: Thread-54] ql.Context: Deleting scratch dir:
hdfs:/
/mycluster/tmp/hive/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:54,961
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] cleanup.EventualCleanupService: Delete h
dfs://mycluster/tmp/hive/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-1
operation was queued2024-06-19T11:27:54,961 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
ql.Context: Deleting scratch dir: file:/
tmp/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-62024-06-19T11:27:54,961
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] cleanup.EventualCleanupService: Delete f
ile:/tmp/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-6
operation was queued2024-06-19T11:27:54,961 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
ql.Context: Deleting scratch dir: file:/
tmp/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:54,961
INFO [00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool:
Thread-54] cleanup.EventualCleanupService: Delete f
ile:/tmp/root/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-1
operation was queued2024-06-19T11:27:54,961 INFO
[00b77a5e-7cec-4e10-a0ae-f94450a56ab0 HiveServer2-Handler-Pool: Thread-54]
operation.SQLOperation: Closing operatio
n log
/tmp/root/operation_logs/00b77a5e-7cec-4e10-a0ae-f94450a56ab0/root_20240619112748_9448d222-0018-4dd7-ba8a-4c30eba4ddd8
without delay2024-06-19T11:27:54,970 INFO [EventualCleanupService thread
0] cleanup.EventualCleanupService: Deleted
file:/tmp/root/00b77a5e-7cec-4e10-a0ae-f9
4450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:54,971
INFO [EventualCleanupService thread 3] cleanup.EventualCleanupService:
Deleted file:/tmp/root/00b77a5e-7cec-4e10-a0ae-f9
4450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-62024-06-19T11:27:54,989
INFO [EventualCleanupService thread 9] cleanup.EventualCleanupService:
Deleted hdfs://mycluster/tmp/hive/root/00b77a5e-7
cec-4e10-a0ae-f94450a56ab0/hive_2024-06-19_11-27-48_655_7337980361533661344-12024-06-19T11:27:56,432
INFO [NotificationEventPoll 0] HiveMetaStore.audit: ugi=root
ip=unknown-ip-addr cmd=get_config_value: name=metast
ore.batch.retrieve.max defaultValue=50 2024-06-19T11:28:02,946 INFO
[Scheduled Query Poller] HiveMetaStore.audit: ugi=root ip=unknown-ip-addr
cmd=scheduled_query_poll
2024-06-19T11:28:56,373 INFO [NotificationEventPoll 0]
HiveMetaStore.audit: ugi=root ip=unknown-ip-addr cmd=get_config_value:
name=metast
ore.batch.retrieve.max defaultValue=50
```
Through my research, I found some answers suggesting that setting set
hive.auto.convert.join=false could resolve the issue. I tried this, and it
indeed worked. However, my question is why the default setting
hive.auto.convert.join=true does not work in Hive 4.0.0? I also tested the
same in Hive 3.x versions and did not encounter any issues. Therefore, I am
unsure about what parameters should be set to use mapjoin in Hive 4.0.0.
Could you please assist me in resolving this issue? I am in urgent need of
a solution.
Thank you.
Best regards,
A loyal Hive user
