hive 编译慢问题处理

Hiveserver2日志分析：找到 阻塞点Waiting to acquire compile lock: show databases。

2025-02-18 13:31:40,612 DEBUG org.apache.thrift.transport.TSaslTransport: [HiveServer2-Handler-Pool: Thread-140]: SERVER: reading data length: 132
2025-02-18 13:31:40,612 DEBUG org.apache.hadoop.security.UserGroupInformation: [HiveServer2-Handler-Pool: Thread-140]: PrivilegedAction as:hive (auth:PROXY) via hive (auth:SIMPLE) from:org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:59)
2025-02-18 13:31:40,613 INFO org.apache.hadoop.hive.conf.HiveConf: [HiveServer2-Handler-Pool: Thread-140]: Using the default value passed
in for log id: 311e73a1-7b14-4919-ab33-ce62cc5b1133
2025-02-18 13:31:40,613 INFO org.apache.hadoop.hive.ql.session.SessionState: [HiveServer2-Handler-Pool: Thread-140]: Updating thread name
to 311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140
2025-02-18 13:31:40,614 INFO org.apache.hive.service.cli.operation.OperationManager: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Adding operation: OperationHandle [opType=EXECUTE_STATEMENT, getHandleIdentifier()=f99a430f-588f-4cac-984b-7ab27faac935]
2025-02-18 13:31:40,614 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]:
2025-02-18 13:31:40,616 DEBUG org.apache.hadoop.hive.ql.lock.CompileLock: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Waiting to acquire compile lock: show databases
时间长的点！
2025-02-18 13:32:15,511 DEBUG org.apache.hadoop.hive.ql.lock.CompileLock: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Acquired the compile lock.
2025-02-18 13:32:15,511 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: </PERFLOG method=waitCompile start=1739856700614 end=1739856735511 duration=34897 from=org.apache.hadoop.hive.ql.Driver>
2025-02-18 13:32:15,511 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]:
2025-02-18 13:32:15,511 DEBUG org.apache.hadoop.hive.conf.VariableSubstitution: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Substitution is on: show databases
2025-02-18 13:32:15,511 INFO org.apache.hadoop.hive.ql.Driver: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Compiling command(queryId=hive_20250218133140_0b366105-26d5-4bd0-a51f-d597590989e3): show databases
2025-02-18 13:32:15,524 DEBUG hive.ql.parse.ParseDriver: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Parsing command: show databases
2025-02-18 13:32:15,524 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: </PERFLOG method=parse start=1739856735524 end=1739856735524 duration=0 from=org.apache.hadoop.hive.ql.Driver>
2025-02-18 13:32:15,524 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]:
2025-02-18 13:32:15,525 INFO hive.metastore: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: HMS client filtering is enabled.
2025-02-18 13:32:15,525 INFO hive.metastore: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Trying to connect to metastore with URI thrift://IT-CDH-Node07:9083
2025-02-18 13:32:15,526 INFO hive.metastore: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Opened a connection to metastore, current connections: 545
2025-02-18 13:32:15,526 INFO hive.metastore: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Connected to metastore.
2025-02-18 13:32:15,668 INFO org.apache.hadoop.hive.ql.Driver: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Semantic Analysis Completed
2025-02-18 13:32:15,668 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: </PERFLOG method=semanticAnalyze start=1739856735524 end=1739856735668 duration=144 from=org.apache.hadoop.hive.ql.Driver>
2025-02-18 13:32:15,669 DEBUG org.apache.hadoop.hive.serde2.lazy.LazySerDeParameters: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: org.apache.hadoop.hive.serde2.lazy.LazySimpleSerDe initialized with: columnNames=[database_name] columnTypes=[string] separator=[[B@16b6ef25] nullstring= lastColumnTakesRest=false timestampFormats=null
2025-02-18 13:32:15,669 INFO org.apache.hadoop.hive.ql.Driver: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:database_name, type:string, comment:from deserializer)], properties:null)
2025-02-18 13:32:15,670 DEBUG org.apache.hadoop.hive.serde2.lazy.LazySerDeParameters: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: org.apache.hadoop.hive.serde2.lazy.LazySimpleSerDe initialized with: columnNames=[database_name] columnTypes=[string] separator=[[B@4e22ab8a] nullstring= lastColumnTakesRest=false timestampFormats=null
2025-02-18 13:32:15,670 INFO org.apache.hadoop.hive.ql.exec.ListSinkOperator: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Initializing operator LIST_SINK[0]
2025-02-18 13:32:15,670 DEBUG org.apache.hadoop.hive.ql.exec.ListSinkOperator: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Initialization Done 0 LIST_SINK
2025-02-18 13:32:15,670 DEBUG org.apache.hadoop.hive.ql.exec.ListSinkOperator: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Operator 0 LIST_SINK initialized
2025-02-18 13:32:15,670 DEBUG org.apache.hadoop.hive.ql.exec.ListSinkOperator: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Initialization Done 0 LIST_SINK done is reset.
2025-02-18 13:32:15,670 DEBUG org.apache.hadoop.hive.ql.log.PerfLogger: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: </PERFLOG method=compile start=1739856735511 end=1739856735670 duration=159 from=org.apache.hadoop.hive.ql.Driver>
2025-02-18 13:32:15,671 INFO hive.ql.metadata.Hive: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Dumping metastore api call timing information for : compilation phase
2025-02-18 13:32:15,671 DEBUG hive.ql.metadata.Hive: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Total time spent in each metastore function (ms): {flushCache_()=141, close_()=0}
2025-02-18 13:32:15,671 INFO org.apache.hadoop.hive.ql.Driver: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Completed compiling command(queryId=hive_20250218133140_0b366105-26d5-4bd0-a51f-d597590989e3); Time taken: 0.159 seconds
2025-02-18 13:32:15,671 DEBUG org.apache.hadoop.security.UserGroupInformation: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: PrivilegedAction as:hive (auth:PROXY) via hive (auth:SIMPLE) from:org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:59)
2025-02-18 13:32:15,672 DEBUG org.apache.hadoop.security.UserGroupInformation: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: PrivilegedAction as:hive (auth:PROXY) via hive (auth:SIMPLE) from:org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:59)
2025-02-18 13:32:15,672 INFO org.apache.hadoop.hive.conf.HiveConf: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Using the default value passed in for log id: 311e73a1-7b14-4919-ab33-ce62cc5b1133
2025-02-18 13:32:15,672 INFO org.apache.hadoop.hive.ql.session.SessionState: [311e73a1-7b14-4919-ab33-ce62cc5b1133 HiveServer2-Handler-Pool: Thread-140]: Resetting thread name to HiveServer2-Handler-Pool: Thread-140
修改CDH配置，打开并行编译！https://cdh.cnc.qianzhan.com/static/help/topics/removing_hive_compilation_lock.html#:~:text=Use%20this%20guide%20to%20plan%20and%20safely,remove%20the%20compilation%20lock%20on%20your%20HiveServer2%20instance.

Driver 代码可以看到，如果 isParallelEnabled=true，则使用 session 内的编译锁，各 session 没有关系。否则使用 globalCompileLock
private ReentrantLock tryAcquireCompileLock(boolean isParallelEnabled,
String command) {
final ReentrantLock compileLock = isParallelEnabled ?
SessionState.get().getCompileLock() : globalCompileLock;