Support Questions
Find answers, ask questions, and share your expertise

Error when trying to run Hive CLI

Error when trying to run Hive CLI

Contributor

Hi,

I am getting the following error when trying to access the Hive CLI.

Also I have enabled debug and the logs are below.

 

[root@sunnymaster02 ~]# hive -hiveconf hive.log.file=debug_hive.log -hiveconf hive.log.dir=/tmp/hiveCLI -hiveconf hive.root.logger=DEBUG,DRFA
Picked up _JAVA_OPTIONS: -Xmx2048m -XX:MaxPermSize=512m -Djava.awt.headless=true
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=512m; support was removed in 8.0
Picked up _JAVA_OPTIONS: -Xmx2048m -XX:MaxPermSize=512m -Djava.awt.headless=true
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=512m; support was removed in 8.0
log4j:WARN No such property [maxFileSize] in org.apache.log4j.DailyRollingFileAppender.

Logging initialized using configuration in file:/etc/hive/2.6.1.0-129/0/hive-log4j.properties
Exception in thread "main" java.lang.RuntimeException: org.apache.tez.dag.api.SessionNotRunning: TezSession has already shutdown. No cluster diagnostics found.
at org.apache.hadoop.hive.ql.session.SessionState.start(SessionState.java:560)
at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:681)
at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:625)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.hadoop.util.RunJar.run(RunJar.java:233)
at org.apache.hadoop.util.RunJar.main(RunJar.java:148)
Caused by: org.apache.tez.dag.api.SessionNotRunning: TezSession has already shutdown. No cluster diagnostics found.
at org.apache.tez.client.TezClient.waitTillReady(TezClient.java:699)
at org.apache.hadoop.hive.ql.exec.tez.TezSessionState.open(TezSessionState.java:218)
at org.apache.hadoop.hive.ql.exec.tez.TezSessionState.open(TezSessionState.java:116)
at org.apache.hadoop.hive.ql.session.SessionState.start(SessionState.java:557)
... 8 more
[root@sunnymaster02 ~]#

 

2021-02-23 23:32:56,250 DEBUG [main]: common.LogUtils (LogUtils.java:logConfigLocation(147)) - Using hive-site.xml found on CLASSPATH at /etc/hive/2.6.1.0-129/0/hive-site.xml
2021-02-23 23:32:56,334 DEBUG [main]: session.SessionState (SessionState.java:<init>(368)) - SessionState user: null
2021-02-23 23:32:56,340 INFO [main]: SessionState (SessionState.java:printInfo(984)) -
Logging initialized using configuration in file:/etc/hive/2.6.1.0-129/0/hive-log4j.properties
2021-02-23 23:32:56,341 DEBUG [main]: parse.VariableSubstitution (VariableSubstitution.java:substitute(53)) - Substitution is on: hive
2021-02-23 23:32:56,433 DEBUG [main]: lib.MutableMetricsFactory (MutableMetricsFactory.java:newForField(42)) - field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginSuccess with annotation @org.apache.hadoop.metrics2.annotation.Metric(about=, sampleName=Ops, always=false, type=DEFAULT, valueName=Time, value=[Rate of successful kerberos logins and latency (milliseconds)])
2021-02-23 23:32:56,437 DEBUG [main]: lib.MutableMetricsFactory (MutableMetricsFactory.java:newForField(42)) - field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginFailure with annotation @org.apache.hadoop.metrics2.annotation.Metric(about=, sampleName=Ops, always=false, type=DEFAULT, valueName=Time, value=[Rate of failed kerberos logins and latency (milliseconds)])
2021-02-23 23:32:56,437 DEBUG [main]: lib.MutableMetricsFactory (MutableMetricsFactory.java:newForField(42)) - field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.getGroups with annotation @org.apache.hadoop.metrics2.annotation.Metric(about=, sampleName=Ops, always=false, type=DEFAULT, valueName=Time, value=[GetGroups])
2021-02-23 23:32:56,438 DEBUG [main]: lib.MutableMetricsFactory (MutableMetricsFactory.java:newForField(42)) - field private org.apache.hadoop.metrics2.lib.MutableGaugeLong org.apache.hadoop.security.UserGroupInformation$UgiMetrics.renewalFailuresTotal with annotation @org.apache.hadoop.metrics2.annotation.Metric(about=, sampleName=Ops, always=false, type=DEFAULT, valueName=Time, value=[Renewal failures since startup])
2021-02-23 23:32:56,438 DEBUG [main]: lib.MutableMetricsFactory (MutableMetricsFactory.java:newForField(42)) - field private org.apache.hadoop.metrics2.lib.MutableGaugeInt org.apache.hadoop.security.UserGroupInformation$UgiMetrics.renewalFailures with annotation @org.apache.hadoop.metrics2.annotation.Metric(about=, sampleName=Ops, always=false, type=DEFAULT, valueName=Time, value=[Renewal failures since last successful login])
2021-02-23 23:32:56,444 DEBUG [main]: impl.MetricsSystemImpl (MetricsSystemImpl.java:register(232)) - UgiMetrics, User and group related metrics
2021-02-23 23:32:56,466 DEBUG [main]: security.SecurityUtil (SecurityUtil.java:setTokenServiceUseIp(116)) - Setting hadoop.security.token.service.use_ip to true
2021-02-23 23:32:56,490 DEBUG [main]: util.KerberosName (KerberosName.java:<clinit>(88)) - Kerberos krb5 configuration not found, setting default realm to empty
2021-02-23 23:32:56,494 DEBUG [main]: security.Groups (Groups.java:getUserToGroupsMappingService(418)) - Creating new Groups object
2021-02-23 23:32:56,496 DEBUG [main]: util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(46)) - Trying to load the custom-built native-hadoop library...
2021-02-23 23:32:56,497 DEBUG [main]: util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(50)) - Loaded the native-hadoop library
2021-02-23 23:32:56,498 DEBUG [main]: security.JniBasedUnixGroupsMapping (JniBasedUnixGroupsMapping.java:<clinit>(50)) - Using JniBasedUnixGroupsMapping for Group resolution
2021-02-23 23:32:56,499 DEBUG [main]: security.JniBasedUnixGroupsMappingWithFallback (JniBasedUnixGroupsMappingWithFallback.java:<init>(45)) - Group mapping impl=org.apache.hadoop.security.JniBasedUnixGroupsMapping
2021-02-23 23:32:56,520 DEBUG [main]: security.Groups (Groups.java:<init>(145)) - Group mapping impl=org.apache.hadoop.security.JniBasedUnixGroupsMappingWithFallback; cacheTimeout=300000; warningDeltaMs=5000
2021-02-23 23:32:56,523 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:login(247)) - hadoop login
2021-02-23 23:32:56,523 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:commit(182)) - hadoop login commit
2021-02-23 23:32:56,527 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:commit(212)) - using local user:UnixPrincipal: root
2021-02-23 23:32:56,527 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:commit(218)) - Using user: "UnixPrincipal: root" with name root
2021-02-23 23:32:56,528 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:commit(228)) - User entry: "root"
2021-02-23 23:32:56,528 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:loginUserFromSubject(855)) - Assuming keytab is managed externally since logged in from subject.
2021-02-23 23:32:56,528 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:loginUserFromSubject(914)) - UGI loginUser:root (auth:SIMPLE)
2021-02-23 23:32:56,543 INFO [main]: hive.metastore (HiveMetaStoreClient.java:open(442)) - Trying to connect to metastore with URI thrift://sunnymaster02.dmicorp.com:9083
2021-02-23 23:32:56,571 INFO [main]: hive.metastore (HiveMetaStoreClient.java:open(538)) - Connected to metastore.
2021-02-23 23:32:56,857 DEBUG [Finalizer]: azure.NativeAzureFileSystem (NativeAzureFileSystem.java:finalize(3152)) - finalize() called.
2021-02-23 23:32:56,858 DEBUG [Finalizer]: azure.NativeAzureFileSystem (NativeAzureFileSystem.java:finalize(3152)) - finalize() called.
2021-02-23 23:32:56,907 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(469)) - dfs.client.use.legacy.blockreader.local = false
2021-02-23 23:32:56,907 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(472)) - dfs.client.read.shortcircuit = true
2021-02-23 23:32:56,907 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(475)) - dfs.client.domain.socket.data.traffic = false
2021-02-23 23:32:56,907 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(478)) - dfs.domain.socket.path = /var/lib/hadoop-hdfs/dn_socket
2021-02-23 23:32:56,939 DEBUG [main]: hdfs.HAUtil (HAUtil.java:cloneDelegationTokenForLogicalUri(329)) - No HA service delegation token found for logical URI hdfs://sunny
2021-02-23 23:32:56,939 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(469)) - dfs.client.use.legacy.blockreader.local = false
2021-02-23 23:32:56,939 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(472)) - dfs.client.read.shortcircuit = true
2021-02-23 23:32:56,939 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(475)) - dfs.client.domain.socket.data.traffic = false
2021-02-23 23:32:56,940 DEBUG [main]: hdfs.BlockReaderLocal (DFSClient.java:<init>(478)) - dfs.domain.socket.path = /var/lib/hadoop-hdfs/dn_socket
2021-02-23 23:32:56,949 DEBUG [main]: retry.RetryUtils (RetryUtils.java:getDefaultRetryPolicy(75)) - multipleLinearRandomRetry = null
2021-02-23 23:32:56,967 DEBUG [main]: ipc.Server (Server.java:registerProtocolEngine(275)) - rpcKind=RPC_PROTOCOL_BUFFER, rpcRequestWrapperClass=class org.apache.hadoop.ipc.ProtobufRpcEngine$RpcRequestWrapper, rpcInvoker=org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker@46268f08
2021-02-23 23:32:56,971 DEBUG [main]: ipc.Client (ClientCache.java:getClient(63)) - getting client out of cache: org.apache.hadoop.ipc.Client@2d6764b2
2021-02-23 23:32:57,277 DEBUG [client DomainSocketWatcher]: unix.DomainSocketWatcher (DomainSocketWatcher.java:run(447)) - org.apache.hadoop.net.unix.DomainSocketWatcher$2@5ab9aa45: starting with interruptCheckPeriodMs = 60000
2021-02-23 23:32:57,280 DEBUG [main]: shortcircuit.DomainSocketFactory (DomainSocketFactory.java:<init>(120)) - The short-circuit local reads feature is enabled.
2021-02-23 23:32:57,285 DEBUG [main]: sasl.DataTransferSaslUtil (DataTransferSaslUtil.java:getSaslPropertiesResolver(183)) - DataTransferProtocol not using SaslPropertiesResolver, no QOP found in configuration for dfs.data.transfer.protection
2021-02-23 23:32:57,312 DEBUG [main]: ipc.Client (Client.java:<init>(465)) - The ping interval is 60000 ms.
2021-02-23 23:32:57,313 DEBUG [main]: ipc.Client (Client.java:setupIOstreams(737)) - Connecting to sunnymaster01.dmicorp.com/10.49.4.11:8020
2021-02-23 23:32:57,327 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:run(1009)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root: starting, having connections 1
2021-02-23 23:32:57,329 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #0
2021-02-23 23:32:57,335 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #0
2021-02-23 23:32:57,335 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 44ms
2021-02-23 23:32:57,362 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #1
2021-02-23 23:32:57,363 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #1
2021-02-23 23:32:57,363 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 2ms
2021-02-23 23:32:57,364 DEBUG [main]: session.SessionState (SessionState.java:createRootHDFSDir(638)) - HDFS root scratch dir: /tmp/hive with schema null, permission: rwx-wx-wx
2021-02-23 23:32:57,364 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #2
2021-02-23 23:32:57,365 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #2
2021-02-23 23:32:57,365 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,390 DEBUG [main]: nativeio.NativeIO (NativeIO.java:<clinit>(195)) - Initialized cache for IDs to User/Group mapping with a cache timeout of 14400 seconds.
2021-02-23 23:32:57,390 INFO [main]: session.SessionState (SessionState.java:createPath(677)) - Created local directory: /tmp/ef66f8ac-53e0-44c8-a133-4f0a820de207_resources
2021-02-23 23:32:57,391 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #3
2021-02-23 23:32:57,392 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #3
2021-02-23 23:32:57,392 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,393 DEBUG [main]: hdfs.DFSClient (DFSClient.java:primitiveMkdir(3069)) - /tmp/hive/root/ef66f8ac-53e0-44c8-a133-4f0a820de207: masked=rwx------
2021-02-23 23:32:57,394 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #4
2021-02-23 23:32:57,402 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #4
2021-02-23 23:32:57,402 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: mkdirs took 8ms
2021-02-23 23:32:57,404 INFO [main]: session.SessionState (SessionState.java:createPath(677)) - Created HDFS directory: /tmp/hive/root/ef66f8ac-53e0-44c8-a133-4f0a820de207
2021-02-23 23:32:57,404 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #5
2021-02-23 23:32:57,405 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #5
2021-02-23 23:32:57,405 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,406 INFO [main]: session.SessionState (SessionState.java:createPath(677)) - Created local directory: /tmp/root/ef66f8ac-53e0-44c8-a133-4f0a820de207
2021-02-23 23:32:57,407 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #6
2021-02-23 23:32:57,407 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #6
2021-02-23 23:32:57,407 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,408 DEBUG [main]: hdfs.DFSClient (DFSClient.java:primitiveMkdir(3069)) - /tmp/hive/root/ef66f8ac-53e0-44c8-a133-4f0a820de207/_tmp_space.db: masked=rwx------
2021-02-23 23:32:57,408 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #7
2021-02-23 23:32:57,412 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #7
2021-02-23 23:32:57,412 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: mkdirs took 4ms
2021-02-23 23:32:57,412 INFO [main]: session.SessionState (SessionState.java:createPath(677)) - Created HDFS directory: /tmp/hive/root/ef66f8ac-53e0-44c8-a133-4f0a820de207/_tmp_space.db
2021-02-23 23:32:57,413 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #8
2021-02-23 23:32:57,414 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #8
2021-02-23 23:32:57,414 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,422 INFO [main]: tez.TezSessionState (TezSessionState.java:open(129)) - Opening the session with id ef66f8ac-53e0-44c8-a133-4f0a820de207 for thread main log trace id - query id -
2021-02-23 23:32:57,422 INFO [main]: tez.TezSessionState (TezSessionState.java:open(145)) - User of session id ef66f8ac-53e0-44c8-a133-4f0a820de207 is root
2021-02-23 23:32:57,423 DEBUG [main]: hdfs.DFSClient (DFSClient.java:primitiveMkdir(3069)) - /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207: masked=rwx------
2021-02-23 23:32:57,424 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #9
2021-02-23 23:32:57,428 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #9
2021-02-23 23:32:57,428 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: mkdirs took 5ms
2021-02-23 23:32:57,428 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #10
2021-02-23 23:32:57,429 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #10
2021-02-23 23:32:57,429 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,430 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #11
2021-02-23 23:32:57,431 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #11
2021-02-23 23:32:57,431 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,456 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #12
2021-02-23 23:32:57,457 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #12
2021-02-23 23:32:57,457 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,458 INFO [main]: tez.DagUtils (DagUtils.java:localizeResource(957)) - Localizing resource because it does not exist: file:/usr/hdp/current/hive-webhcat/share/hcatalog/hive-hcatalog-core.jar to dest: hdfs://sunny/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar
2021-02-23 23:32:57,461 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #13
2021-02-23 23:32:57,462 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #13
2021-02-23 23:32:57,462 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 2ms
2021-02-23 23:32:57,465 DEBUG [main]: hdfs.DFSClient (DFSClient.java:create(1699)) - /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar: masked=rw-------
2021-02-23 23:32:57,485 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #14
2021-02-23 23:32:57,490 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #14
2021-02-23 23:32:57,490 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: create took 5ms
2021-02-23 23:32:57,513 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:57,519 DEBUG [LeaseRenewer:root@sunny]: hdfs.LeaseRenewer (LeaseRenewer.java:run(301)) - Lease renewer daemon for [DFSClient_NONMAPREDUCE_-658166724_1] with renew id 1 started
2021-02-23 23:32:57,521 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=0, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, packetSize=65016, chunksPerPacket=126, bytesCurBlock=0
2021-02-23 23:32:57,521 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2032)) - DFSClient writeChunk packet full seqno=0, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, bytesCurBlock=64512, blockSize=134217728, appendChunk=false
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 0
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=1, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, packetSize=65016, chunksPerPacket=126, bytesCurBlock=64512
2021-02-23 23:32:57,522 DEBUG [Thread-7]: hdfs.DFSClient (DFSOutputStream.java:run(556)) - Allocating new block
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2032)) - DFSClient writeChunk packet full seqno=1, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, bytesCurBlock=129024, blockSize=134217728, appendChunk=false
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 1
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:57,522 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=2, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, packetSize=65016, chunksPerPacket=126, bytesCurBlock=129024
2021-02-23 23:32:57,523 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2032)) - DFSClient writeChunk packet full seqno=2, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, bytesCurBlock=193536, blockSize=134217728, appendChunk=false
2021-02-23 23:32:57,523 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 2
2021-02-23 23:32:57,523 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:57,523 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=3, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, packetSize=65016, chunksPerPacket=126, bytesCurBlock=193536
2021-02-23 23:32:57,523 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2032)) - DFSClient writeChunk packet full seqno=3, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, bytesCurBlock=258048, blockSize=134217728, appendChunk=false
2021-02-23 23:32:57,523 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 3
2021-02-23 23:32:57,524 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:57,524 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=4, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar, packetSize=65016, chunksPerPacket=126, bytesCurBlock=258048
2021-02-23 23:32:57,524 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 4
2021-02-23 23:32:57,524 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 5
2021-02-23 23:32:57,524 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:waitForAckedSeqno(2332)) - Waiting for ack for: 5
2021-02-23 23:32:57,534 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #15
2021-02-23 23:32:57,537 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #15
2021-02-23 23:32:57,538 DEBUG [Thread-7]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: addBlock took 5ms
2021-02-23 23:32:57,546 DEBUG [Thread-7]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK]
2021-02-23 23:32:57,546 DEBUG [Thread-7]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.26:50010,DS-b0bc97ea-4d5b-40e9-b2ff-729838b7ce06,DISK]
2021-02-23 23:32:57,546 DEBUG [Thread-7]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.23:50010,DS-f02ecd22-d558-4838-8bb5-1b685111013f,DISK]
2021-02-23 23:32:57,546 DEBUG [Thread-7]: hdfs.DFSClient (DFSOutputStream.java:createSocketForPipeline(1682)) - Connecting to datanode 10.49.4.25:50010
2021-02-23 23:32:57,547 DEBUG [Thread-7]: hdfs.DFSClient (DFSOutputStream.java:createSocketForPipeline(1694)) - Send buf size 131072
2021-02-23 23:32:57,547 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #16
2021-02-23 23:32:57,548 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #16
2021-02-23 23:32:57,548 DEBUG [Thread-7]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getServerDefaults took 1ms
2021-02-23 23:32:57,552 DEBUG [Thread-7]: sasl.SaslDataTransferClient (SaslDataTransferClient.java:send(244)) - SASL client skipping handshake in unsecured configuration for addr = /10.49.4.25, datanodeId = DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK]
2021-02-23 23:32:57,626 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:initDataStreaming(461)) - nodes[DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK], DatanodeInfoWithStorage[10.49.4.26:50010,DS-b0bc97ea-4d5b-40e9-b2ff-729838b7ce06,DISK], DatanodeInfoWithStorage[10.49.4.23:50010,DS-f02ecd22-d558-4838-8bb5-1b685111013f,DISK]]storageTypes[DISK, DISK, DISK]storageIDs [DS-0eb500cf-f296-4989-a6f8-875acdb771dd, DS-b0bc97ea-4d5b-40e9-b2ff-729838b7ce06, DS-f02ecd22-d558-4838-8bb5-1b685111013f]
2021-02-23 23:32:57,627 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094 sending packet packet seqno: 0 offsetInBlock: 0 lastPacketInBlock: false lastByteOffsetInBlock: 64512
2021-02-23 23:32:57,628 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094 sending packet packet seqno: 1 offsetInBlock: 64512 lastPacketInBlock: false lastByteOffsetInBlock: 129024
2021-02-23 23:32:57,628 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094 sending packet packet seqno: 2 offsetInBlock: 129024 lastPacketInBlock: false lastByteOffsetInBlock: 193536
2021-02-23 23:32:57,628 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094 sending packet packet seqno: 3 offsetInBlock: 193536 lastPacketInBlock: false lastByteOffsetInBlock: 258048
2021-02-23 23:32:57,630 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094 sending packet packet seqno: 4 offsetInBlock: 258048 lastPacketInBlock: false lastByteOffsetInBlock: 262046
2021-02-23 23:32:57,685 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 0 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 5278868 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:57,687 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 1 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 4515159 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:57,687 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 2 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 3436304 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:57,687 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 3 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 2802067 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:57,687 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 4 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 2898289 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:57,688 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094 sending packet packet seqno: 5 offsetInBlock: 262046 lastPacketInBlock: true lastByteOffsetInBlock: 262046
2021-02-23 23:32:57,695 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 5 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 5268222 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:57,695 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/hive-hcatalog-core.jar block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094]: hdfs.DFSClient (DFSOutputStream.java:endBlock(472)) - Closing old block BP-649762993-10.49.4.11-1611279739674:blk_1073746848_6094
2021-02-23 23:32:57,697 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #17
2021-02-23 23:32:57,700 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #17
2021-02-23 23:32:57,700 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: complete took 3ms
2021-02-23 23:32:57,703 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #18
2021-02-23 23:32:57,704 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #18
2021-02-23 23:32:57,704 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,726 INFO [main]: tez.DagUtils (DagUtils.java:createLocalResource(723)) - Resource modification time: 1614144777698
2021-02-23 23:32:57,742 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #19
2021-02-23 23:32:57,743 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #19
2021-02-23 23:32:57,743 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 2ms
2021-02-23 23:32:57,743 DEBUG [main]: hdfs.DFSClient (DFSClient.java:primitiveMkdir(3069)) - /user/root/.hiveJars: masked=rwx------
2021-02-23 23:32:57,743 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #20
2021-02-23 23:32:57,744 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #20
2021-02-23 23:32:57,744 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: mkdirs took 1ms
2021-02-23 23:32:57,744 INFO [main]: tez.DagUtils (DagUtils.java:getHiveJarDirectory(881)) - Jar dir is null/directory doesn't exist. Choosing HIVE_INSTALL_DIR - /user/root/.hiveJars
2021-02-23 23:32:57,745 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #21
2021-02-23 23:32:57,745 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #21
2021-02-23 23:32:57,746 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,906 DEBUG [main]: tez.TezSessionState (TezSessionState.java:createJarLocalResource(381)) - The destination file name for [file:/usr/hdp/2.6.1.0-129/hive/lib/hive-exec-1.2.1000.2.6.1.0-129.jar] is hive-exec-1.2.1000.2.6.1.0-129-bc35e93470f0da2b3ade0244c31fde2996527667f3fc7e9286e352f55198fc82.jar
2021-02-23 23:32:57,907 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #22
2021-02-23 23:32:57,908 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #22
2021-02-23 23:32:57,908 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,909 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #23
2021-02-23 23:32:57,910 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #23
2021-02-23 23:32:57,910 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:57,910 INFO [main]: tez.DagUtils (DagUtils.java:createLocalResource(723)) - Resource modification time: 1614119414829
2021-02-23 23:32:57,955 INFO [main]: sqlstd.SQLStdHiveAccessController (SQLStdHiveAccessController.java:<init>(95)) - Created SQLStdHiveAccessController for session context : HiveAuthzSessionContext [sessionString=ef66f8ac-53e0-44c8-a133-4f0a820de207, clientType=HIVECLI]
2021-02-23 23:32:57,956 INFO [main]: hive.metastore (HiveMetaStoreClient.java:isCompatibleWith(344)) - Mestastore configuration hive.metastore.filter.hook changed from org.apache.hadoop.hive.metastore.DefaultMetaStoreFilterHookImpl to org.apache.hadoop.hive.ql.security.authorization.plugin.AuthorizationMetaStoreFilterHook
2021-02-23 23:32:57,956 DEBUG [main]: metadata.Hive (Hive.java:get(273)) - Creating new db. db = org.apache.hadoop.hive.ql.metadata.Hive@46292372, needsRefresh = true, db.isCurrentUserOwner = true
2021-02-23 23:32:57,956 DEBUG [main]: metadata.Hive (Hive.java:close(334)) - Closing current thread's connection to Hive Metastore.
2021-02-23 23:32:57,961 INFO [main]: hive.metastore (HiveMetaStoreClient.java:open(442)) - Trying to connect to metastore with URI thrift://sunnymaster02.dmicorp.com:9083
2021-02-23 23:32:57,962 INFO [main]: hive.metastore (HiveMetaStoreClient.java:open(538)) - Connected to metastore.



1 REPLY 1

Re: Error when trying to run Hive CLI

Contributor

Here is the other half of the debug logs

 

2021-02-23 23:32:57,966 DEBUG [main]: session.SessionState (SessionState.java:setupAuth(797)) - Session is using authorization class class org.apache.hadoop.hive.ql.security.authorization.plugin.HiveAuthorizerImpl
2021-02-23 23:32:57,971 DEBUG [main]: tez.TezSessionState (TezSessionState.java:setupSessionAcls(242)) - Setting Tez Session access for sessionId=ef66f8ac-53e0-44c8-a133-4f0a820de207 with viewAclString=*, modifyStr=root
2021-02-23 23:32:58,146 INFO [main]: client.TezClient (TezClient.java:<init>(177)) - Tez Client Version: [ component=tez-api, version=0.7.0.2.6.1.0-129, revision=bbcfb9e8d9cc93fb586b32199eb9492528449f7c, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=2017-05-31T03:06:59Z ]
2021-02-23 23:32:58,146 INFO [main]: tez.TezSessionState (TezSessionState.java:open(193)) - Opening new Tez Session (id: ef66f8ac-53e0-44c8-a133-4f0a820de207, scratch dir: hdfs://sunny/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207)
2021-02-23 23:32:58,157 DEBUG [main]: service.AbstractService (AbstractService.java:enterState(452)) - Service: org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state INITED
2021-02-23 23:32:58,199 DEBUG [main]: service.AbstractService (AbstractService.java:enterState(452)) - Service: org.apache.hadoop.yarn.client.api.impl.AHSClientImpl entered state INITED
2021-02-23 23:32:58,205 DEBUG [main]: client.RMProxy (RMProxy.java:createRetryPolicy(288)) - Created non-failover retry policy: RetryUpToMaximumCountWithFixedSleep(maxRetries=2147483647, sleepTime=15000 MILLISECONDS)
2021-02-23 23:32:58,206 INFO [main]: client.RMProxy (RMProxy.java:newProxyInstance(125)) - Connecting to ResourceManager at sunnymaster01.dmicorp.com/10.49.4.11:8050
2021-02-23 23:32:58,207 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:logPrivilegedAction(1893)) - PrivilegedAction as:root (auth:SIMPLE) from:org.apache.hadoop.yarn.client.RMProxy.getProxy(RMProxy.java:163)
2021-02-23 23:32:58,208 DEBUG [main]: ipc.YarnRPC (YarnRPC.java:create(59)) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC
2021-02-23 23:32:58,209 DEBUG [main]: ipc.HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy(47)) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ApplicationClientProtocol
2021-02-23 23:32:58,233 DEBUG [main]: ipc.Client (ClientCache.java:getClient(63)) - getting client out of cache: org.apache.hadoop.ipc.Client@2d6764b2
2021-02-23 23:32:58,352 INFO [main]: client.AHSProxy (AHSProxy.java:createAHSProxy(42)) - Connecting to Application History server at sunnymaster01.dmicorp.com/10.49.4.11:10200
2021-02-23 23:32:58,353 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:logPrivilegedAction(1893)) - PrivilegedAction as:root (auth:SIMPLE) from:org.apache.hadoop.yarn.client.AHSProxy.getProxy(AHSProxy.java:49)
2021-02-23 23:32:58,353 DEBUG [main]: ipc.YarnRPC (YarnRPC.java:create(59)) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC
2021-02-23 23:32:58,353 DEBUG [main]: ipc.HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy(47)) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ApplicationHistoryProtocol
2021-02-23 23:32:58,355 DEBUG [main]: ipc.Client (ClientCache.java:getClient(63)) - getting client out of cache: org.apache.hadoop.ipc.Client@2d6764b2
2021-02-23 23:32:58,357 DEBUG [main]: service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.client.api.impl.AHSClientImpl is started
2021-02-23 23:32:58,358 DEBUG [main]: service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.client.api.impl.YarnClientImpl is started
2021-02-23 23:32:58,359 INFO [main]: client.TezClient (TezClient.java:start(351)) - Session mode. Starting session.
2021-02-23 23:32:58,362 INFO [main]: client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: /hdp/apps/2.6.1.0-129/tez/tez.tar.gz
2021-02-23 23:32:58,363 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #24
2021-02-23 23:32:58,364 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #24
2021-02-23 23:32:58,364 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 2ms
2021-02-23 23:32:58,364 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #25
2021-02-23 23:32:58,365 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #25
2021-02-23 23:32:58,365 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,366 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #26
2021-02-23 23:32:58,367 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #26
2021-02-23 23:32:58,367 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,367 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #27
2021-02-23 23:32:58,368 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #27
2021-02-23 23:32:58,368 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,368 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #28
2021-02-23 23:32:58,369 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #28
2021-02-23 23:32:58,369 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,370 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #29
2021-02-23 23:32:58,370 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #29
2021-02-23 23:32:58,371 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,371 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #30
2021-02-23 23:32:58,372 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #30
2021-02-23 23:32:58,372 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,372 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #31
2021-02-23 23:32:58,373 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #31
2021-02-23 23:32:58,373 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,374 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #32
2021-02-23 23:32:58,374 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #32
2021-02-23 23:32:58,375 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,386 DEBUG [main]: ipc.Client (Client.java:<init>(465)) - The ping interval is 60000 ms.
2021-02-23 23:32:58,387 DEBUG [main]: ipc.Client (Client.java:setupIOstreams(737)) - Connecting to sunnymaster01.dmicorp.com/10.49.4.11:8050
2021-02-23 23:32:58,388 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:run(1009)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root: starting, having connections 2
2021-02-23 23:32:58,388 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #33
2021-02-23 23:32:58,389 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #33
2021-02-23 23:32:58,389 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getNewApplication took 3ms
2021-02-23 23:32:58,395 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #34
2021-02-23 23:32:58,396 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #34
2021-02-23 23:32:58,396 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,397 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #35
2021-02-23 23:32:58,398 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #35
2021-02-23 23:32:58,398 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,398 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #36
2021-02-23 23:32:58,399 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #36
2021-02-23 23:32:58,399 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,400 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #37
2021-02-23 23:32:58,401 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #37
2021-02-23 23:32:58,401 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,401 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #38
2021-02-23 23:32:58,402 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #38
2021-02-23 23:32:58,402 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,403 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #39
2021-02-23 23:32:58,403 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #39
2021-02-23 23:32:58,404 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,404 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #40
2021-02-23 23:32:58,405 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #40
2021-02-23 23:32:58,405 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,405 DEBUG [main]: hdfs.DFSClient (DFSClient.java:primitiveMkdir(3069)) - /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007: masked=rwx------
2021-02-23 23:32:58,405 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #41
2021-02-23 23:32:58,408 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #41
2021-02-23 23:32:58,408 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: mkdirs took 3ms
2021-02-23 23:32:58,408 INFO [main]: client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(122)) - Tez system stage directory hdfs://sunny/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007 doesn't exist and is created
2021-02-23 23:32:58,410 DEBUG [main]: client.TezClientUtils (TezClientUtils.java:createApplicationSubmissionContext(442)) - AppMaster capability = <memory:4096, vCores:1>
2021-02-23 23:32:58,411 DEBUG [main]: client.TezClientUtils (TezClientUtils.java:createApplicationSubmissionContext(503)) - Command to launch container for ApplicationMaster is : $JAVA_HOME/bin/java -Xmx3276m -Djava.io.tmpdir=$PWD/tmp -server -Djava.net.preferIPv4Stack=true -Dhdp.version=2.6.1.0-129 -XX:+PrintGCDetails -verbose:gc -XX:+PrintGCTimeStamps -XX:+UseNUMA -XX:+UseG1GC -XX:+ResizeTLAB -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator -Dlog4j.configuration=tez-container-log4j.properties -Dyarn.app.container.log.dir=<LOG_DIR> -Dtez.root.logger=INFO,CLA -Dsun.nio.ch.bugLevel='' org.apache.tez.dag.app.DAGAppMaster --session 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr
2021-02-23 23:32:58,425 DEBUG [main]: hdfs.DFSClient (DFSClient.java:create(1699)) - /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb: masked=rw-------
2021-02-23 23:32:58,426 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #42
2021-02-23 23:32:58,429 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #42
2021-02-23 23:32:58,429 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: create took 3ms
2021-02-23 23:32:58,429 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:58,431 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #43
2021-02-23 23:32:58,433 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #43
2021-02-23 23:32:58,433 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: setPermission took 2ms
2021-02-23 23:32:58,438 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=0, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb, packetSize=65016, chunksPerPacket=126, bytesCurBlock=0
2021-02-23 23:32:58,442 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2032)) - DFSClient writeChunk packet full seqno=0, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb, bytesCurBlock=64512, blockSize=134217728, appendChunk=false
2021-02-23 23:32:58,442 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 0
2021-02-23 23:32:58,442 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:58,442 DEBUG [Thread-11]: hdfs.DFSClient (DFSOutputStream.java:run(556)) - Allocating new block
2021-02-23 23:32:58,442 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=1, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb, packetSize=65016, chunksPerPacket=126, bytesCurBlock=64512
2021-02-23 23:32:58,442 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #44
2021-02-23 23:32:58,443 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 1
2021-02-23 23:32:58,443 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 2
2021-02-23 23:32:58,443 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:waitForAckedSeqno(2332)) - Waiting for ack for: 2
2021-02-23 23:32:58,445 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #44
2021-02-23 23:32:58,446 DEBUG [Thread-11]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: addBlock took 4ms
2021-02-23 23:32:58,446 DEBUG [Thread-11]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.24:50010,DS-7c7307a4-3c0c-407c-a462-4b6841415eb4,DISK]
2021-02-23 23:32:58,446 DEBUG [Thread-11]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK]
2021-02-23 23:32:58,446 DEBUG [Thread-11]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.23:50010,DS-f02ecd22-d558-4838-8bb5-1b685111013f,DISK]
2021-02-23 23:32:58,446 DEBUG [Thread-11]: hdfs.DFSClient (DFSOutputStream.java:createSocketForPipeline(1682)) - Connecting to datanode 10.49.4.24:50010
2021-02-23 23:32:58,447 DEBUG [Thread-11]: hdfs.DFSClient (DFSOutputStream.java:createSocketForPipeline(1694)) - Send buf size 131072
2021-02-23 23:32:58,447 DEBUG [Thread-11]: sasl.SaslDataTransferClient (SaslDataTransferClient.java:send(244)) - SASL client skipping handshake in unsecured configuration for addr = /10.49.4.24, datanodeId = DatanodeInfoWithStorage[10.49.4.24:50010,DS-7c7307a4-3c0c-407c-a462-4b6841415eb4,DISK]
2021-02-23 23:32:58,455 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:initDataStreaming(461)) - nodes[DatanodeInfoWithStorage[10.49.4.24:50010,DS-7c7307a4-3c0c-407c-a462-4b6841415eb4,DISK], DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK], DatanodeInfoWithStorage[10.49.4.23:50010,DS-f02ecd22-d558-4838-8bb5-1b685111013f,DISK]]storageTypes[DISK, DISK, DISK]storageIDs [DS-7c7307a4-3c0c-407c-a462-4b6841415eb4, DS-0eb500cf-f296-4989-a6f8-875acdb771dd, DS-f02ecd22-d558-4838-8bb5-1b685111013f]
2021-02-23 23:32:58,456 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095 sending packet packet seqno: 0 offsetInBlock: 0 lastPacketInBlock: false lastByteOffsetInBlock: 64512
2021-02-23 23:32:58,456 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095 sending packet packet seqno: 1 offsetInBlock: 64512 lastPacketInBlock: false lastByteOffsetInBlock: 85872
2021-02-23 23:32:58,462 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 0 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 4221619 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:58,463 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 1 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 4202202 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:58,463 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095 sending packet packet seqno: 2 offsetInBlock: 85872 lastPacketInBlock: true lastByteOffsetInBlock: 85872
2021-02-23 23:32:58,470 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 2 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 5726222 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:58,471 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez-conf.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095]: hdfs.DFSClient (DFSOutputStream.java:endBlock(472)) - Closing old block BP-649762993-10.49.4.11-1611279739674:blk_1073746849_6095
2021-02-23 23:32:58,471 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #45
2021-02-23 23:32:58,473 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #45
2021-02-23 23:32:58,474 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: complete took 3ms
2021-02-23 23:32:58,474 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #46
2021-02-23 23:32:58,475 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #46
2021-02-23 23:32:58,476 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 2ms
2021-02-23 23:32:58,476 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #47
2021-02-23 23:32:58,477 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #47
2021-02-23 23:32:58,477 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,477 DEBUG [main]: hdfs.DFSClient (DFSClient.java:create(1699)) - /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb: masked=rw-------
2021-02-23 23:32:58,477 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #48
2021-02-23 23:32:58,480 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #48
2021-02-23 23:32:58,480 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: create took 3ms
2021-02-23 23:32:58,481 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:computePacketChunkSize(1918)) - computePacketChunkSize: src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb, chunkSize=516, chunksPerPacket=126, packetSize=65016
2021-02-23 23:32:58,481 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #49
2021-02-23 23:32:58,483 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #49
2021-02-23 23:32:58,483 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: setPermission took 2ms
2021-02-23 23:32:58,501 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:writeChunkImpl(2013)) - DFSClient writeChunk allocating new packet seqno=0, src=/tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb, packetSize=65016, chunksPerPacket=126, bytesCurBlock=0
2021-02-23 23:32:58,501 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 0
2021-02-23 23:32:58,501 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:queueCurrentPacket(1932)) - Queued packet 1
2021-02-23 23:32:58,502 DEBUG [main]: hdfs.DFSClient (DFSOutputStream.java:waitForAckedSeqno(2332)) - Waiting for ack for: 1
2021-02-23 23:32:58,502 DEBUG [Thread-13]: hdfs.DFSClient (DFSOutputStream.java:run(556)) - Allocating new block
2021-02-23 23:32:58,502 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #50
2021-02-23 23:32:58,505 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #50
2021-02-23 23:32:58,505 DEBUG [Thread-13]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: addBlock took 3ms
2021-02-23 23:32:58,506 DEBUG [Thread-13]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.24:50010,DS-7c7307a4-3c0c-407c-a462-4b6841415eb4,DISK]
2021-02-23 23:32:58,506 DEBUG [Thread-13]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.23:50010,DS-f02ecd22-d558-4838-8bb5-1b685111013f,DISK]
2021-02-23 23:32:58,506 DEBUG [Thread-13]: hdfs.DFSClient (DFSOutputStream.java:createBlockOutputStream(1413)) - pipeline = DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK]
2021-02-23 23:32:58,506 DEBUG [Thread-13]: hdfs.DFSClient (DFSOutputStream.java:createSocketForPipeline(1682)) - Connecting to datanode 10.49.4.24:50010
2021-02-23 23:32:58,506 DEBUG [Thread-13]: hdfs.DFSClient (DFSOutputStream.java:createSocketForPipeline(1694)) - Send buf size 131072
2021-02-23 23:32:58,506 DEBUG [Thread-13]: sasl.SaslDataTransferClient (SaslDataTransferClient.java:send(244)) - SASL client skipping handshake in unsecured configuration for addr = /10.49.4.24, datanodeId = DatanodeInfoWithStorage[10.49.4.24:50010,DS-7c7307a4-3c0c-407c-a462-4b6841415eb4,DISK]
2021-02-23 23:32:58,514 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096]: hdfs.DFSClient (DFSOutputStream.java:initDataStreaming(461)) - nodes[DatanodeInfoWithStorage[10.49.4.24:50010,DS-7c7307a4-3c0c-407c-a462-4b6841415eb4,DISK], DatanodeInfoWithStorage[10.49.4.23:50010,DS-f02ecd22-d558-4838-8bb5-1b685111013f,DISK], DatanodeInfoWithStorage[10.49.4.25:50010,DS-0eb500cf-f296-4989-a6f8-875acdb771dd,DISK]]storageTypes[DISK, DISK, DISK]storageIDs [DS-7c7307a4-3c0c-407c-a462-4b6841415eb4, DS-f02ecd22-d558-4838-8bb5-1b685111013f, DS-0eb500cf-f296-4989-a6f8-875acdb771dd]
2021-02-23 23:32:58,514 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096 sending packet packet seqno: 0 offsetInBlock: 0 lastPacketInBlock: false lastByteOffsetInBlock: 642
2021-02-23 23:32:58,518 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 0 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 2637342 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:58,518 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096]: hdfs.DFSClient (DFSOutputStream.java:run(610)) - DataStreamer block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096 sending packet packet seqno: 1 offsetInBlock: 642 lastPacketInBlock: true lastByteOffsetInBlock: 642
2021-02-23 23:32:58,525 DEBUG [ResponseProcessor for block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096]: hdfs.DFSClient (DFSOutputStream.java:run(852)) - DFSClient seqno: 1 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 5490934 flag: 0 flag: 0 flag: 0
2021-02-23 23:32:58,525 DEBUG [DataStreamer for file /tmp/hive/root/_tez_session_dir/ef66f8ac-53e0-44c8-a133-4f0a820de207/.tez/application_1614143640940_0007/tez.session.local-resources.pb block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096]: hdfs.DFSClient (DFSOutputStream.java:endBlock(472)) - Closing old block BP-649762993-10.49.4.11-1611279739674:blk_1073746850_6096
2021-02-23 23:32:58,526 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #51
2021-02-23 23:32:58,528 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #51
2021-02-23 23:32:58,529 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: complete took 4ms
2021-02-23 23:32:58,529 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #52
2021-02-23 23:32:58,530 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #52
2021-02-23 23:32:58,530 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,530 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #53
2021-02-23 23:32:58,531 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #53
2021-02-23 23:32:58,531 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:32:58,552 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #54
2021-02-23 23:32:58,556 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #54
2021-02-23 23:32:58,556 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: submitApplication took 5ms
2021-02-23 23:32:58,560 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #55
2021-02-23 23:32:58,564 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #55
2021-02-23 23:32:58,564 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 4ms
2021-02-23 23:32:58,575 INFO [main]: impl.YarnClientImpl (YarnClientImpl.java:submitApplication(274)) - Submitted application application_1614143640940_0007
2021-02-23 23:32:58,575 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #56
2021-02-23 23:32:58,576 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #56
2021-02-23 23:32:58,577 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 2ms
2021-02-23 23:32:58,577 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #57
2021-02-23 23:32:58,578 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #57
2021-02-23 23:32:58,578 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 1ms
2021-02-23 23:32:58,578 INFO [main]: client.TezClient (TezClient.java:start(385)) - The url to track the Tez Session: http://sunnymaster01.dmicorp.com:8088/proxy/application_1614143640940_0007/
2021-02-23 23:32:58,578 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #58
2021-02-23 23:32:58,579 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #58
2021-02-23 23:32:58,579 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 1ms
2021-02-23 23:32:59,080 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #59
2021-02-23 23:32:59,082 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #59
2021-02-23 23:32:59,083 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 3ms
2021-02-23 23:32:59,583 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #60
2021-02-23 23:32:59,585 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #60
2021-02-23 23:32:59,585 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 2ms
2021-02-23 23:33:00,086 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #61
2021-02-23 23:33:00,088 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #61
2021-02-23 23:33:00,088 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 2ms
2021-02-23 23:33:00,589 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #62
2021-02-23 23:33:00,591 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #62
2021-02-23 23:33:00,591 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 3ms
2021-02-23 23:33:01,092 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #63
2021-02-23 23:33:01,094 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #63
2021-02-23 23:33:01,094 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 2ms
2021-02-23 23:33:01,594 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #64
2021-02-23 23:33:01,596 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #64
2021-02-23 23:33:01,596 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 2ms
2021-02-23 23:33:01,597 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root sending #65
2021-02-23 23:33:01,598 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8050 from root got value #65
2021-02-23 23:33:01,598 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getApplicationReport took 2ms
2021-02-23 23:33:01,599 DEBUG [main]: client.TezClientUtils (TezClientUtils.java:getAMProxy(875)) - Connecting to Tez AM at sunnydn04.dmicorp.com/10.49.4.24:42647
2021-02-23 23:33:01,601 DEBUG [main]: security.UserGroupInformation (UserGroupInformation.java:logPrivilegedAction(1893)) - PrivilegedAction as:root (auth:SIMPLE) from:org.apache.tez.client.TezClientUtils.getAMProxy(TezClientUtils.java:879)
2021-02-23 23:33:01,603 DEBUG [main]: ipc.Client (ClientCache.java:getClient(63)) - getting client out of cache: org.apache.hadoop.ipc.Client@2d6764b2
2021-02-23 23:33:01,648 DEBUG [main]: ipc.Client (Client.java:<init>(465)) - The ping interval is 60000 ms.
2021-02-23 23:33:01,648 DEBUG [main]: ipc.Client (Client.java:setupIOstreams(737)) - Connecting to sunnydn04.dmicorp.com/10.49.4.24:42647
2021-02-23 23:33:01,649 DEBUG [IPC Client (1633013890) connection to sunnydn04.dmicorp.com/10.49.4.24:42647 from root]: ipc.Client (Client.java:run(1009)) - IPC Client (1633013890) connection to sunnydn04.dmicorp.com/10.49.4.24:42647 from root: starting, having connections 3
2021-02-23 23:33:01,650 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnydn04.dmicorp.com/10.49.4.24:42647 from root sending #66
2021-02-23 23:33:01,739 DEBUG [IPC Client (1633013890) connection to sunnydn04.dmicorp.com/10.49.4.24:42647 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnydn04.dmicorp.com/10.49.4.24:42647 from root got value #66
2021-02-23 23:33:01,739 DEBUG [main]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getAMStatus took 92ms
2021-02-23 23:33:01,752 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #67
2021-02-23 23:33:01,753 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #67
2021-02-23 23:33:01,753 DEBUG [pool-1-thread-1]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:33:01,756 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #68
2021-02-23 23:33:01,758 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #68
2021-02-23 23:33:01,759 DEBUG [pool-1-thread-1]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: delete took 3ms
2021-02-23 23:33:01,796 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #69
2021-02-23 23:33:01,797 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #69
2021-02-23 23:33:01,797 DEBUG [pool-1-thread-1]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:33:01,797 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #70
2021-02-23 23:33:01,798 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #70
2021-02-23 23:33:01,798 DEBUG [pool-1-thread-1]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: getFileInfo took 1ms
2021-02-23 23:33:01,799 DEBUG [IPC Parameter Sending Thread #0]: ipc.Client (Client.java:run(1072)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root sending #71
2021-02-23 23:33:01,802 DEBUG [IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root]: ipc.Client (Client.java:receiveRpcResponse(1129)) - IPC Client (1633013890) connection to sunnymaster01.dmicorp.com/10.49.4.11:8020 from root got value #71
2021-02-23 23:33:01,802 DEBUG [pool-1-thread-1]: ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(254)) - Call: delete took 3ms
2021-02-23 23:33:01,802 DEBUG [pool-1-thread-1]: ipc.Client (ClientCache.java:stopClient(97)) - stopping client from cache: org.apache.hadoop.ipc.Client@2d6764b2
2021-02-23 23:33:01,804 DEBUG [Thread-0]: util.ShutdownHookManager (ShutdownHookManager.java:run(84)) - ShutdownHookManger complete shutdown.