Filed https://issues.apache.org/jira/browse/TEZ-2133 !
Not sure if in this case the AM was the same, but generally both exceptions are in the same log! best Johannes > On 30 Jan 2015, at 19:23, Hitesh Shah <[email protected]> wrote: > > Hi Johannes, > > Sorry - missed this email earlier. I have seen this a couple of times but > have not been able to track down the root cause of this. Would you mind > filing a jira for this with the logs from an AM where you observed this? > Also, if you have a higher frequency of being able to reproduce this, can you > run the AM at DEBUG or even TRACE log level. > > For the most part, from what I have seen, this only shows up on a session > shutdown and likely does not affect Hive queries as the Hive layer will > delete its scratch/staging dir in any case. Just to confirm - the lease > expiry log is from a different AM? > > — Hitesh > > On Jan 30, 2015, at 6:08 AM, Johannes Zillmann <[email protected]> > wrote: > >> No idea here ? >> >> Johannes >> >>> On 15 Jan 2015, at 18:07, Johannes Zillmann <[email protected]> >>> wrote: >>> >>> Hey guys, >>> >>> running Tez-0.5.2 with secure impersonation / kerberos. Importing data from >>> secured hive. >>> Job is successful. But in the logs i find those warnings: >>> >>> --------------------------------------------------------------------------------- >>> 2015-01-14 17:05:49,150 INFO [Thread-1] >>> org.apache.tez.dag.app.DAGAppMaster: DAGAppMasterShutdownHook invoked >>> 2015-01-14 17:05:49,151 INFO [Thread-1] >>> org.apache.tez.dag.app.DAGAppMaster: The shutdown handler is still running, >>> waiting for it to complete >>> 2015-01-14 17:05:49,153 WARN [AMShutdownThread] >>> org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException >>> as:qa (auth:TOKEN) cause:org.apache.hadoop.security.AccessControlException: >>> Client cannot authenticate via:[TOKEN, KERBEROS] >>> 2015-01-14 17:05:49,164 WARN [AMShutdownThread] >>> org.apache.hadoop.ipc.Client: Exception encountered while connecting to the >>> server : org.apache.hadoop.security.AccessControlException: Client cannot >>> authenticate via:[TOKEN, KERBEROS] >>> 2015-01-14 17:05:49,165 WARN [AMShutdownThread] >>> org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException >>> as:qa (auth:TOKEN) cause:java.io.IOException: >>> org.apache.hadoop.security.AccessControlException: Client cannot >>> authenticate via:[TOKEN, KERBEROS] >>> 2015-01-14 17:05:49,165 WARN [AMShutdownThread] >>> org.apache.tez.dag.app.DAGAppMaster: Failed to delete tez scratch data dir >>> java.io.IOException: Failed on local exception: java.io.IOException: >>> org.apache.hadoop.security.AccessControlException: Client cannot >>> authenticate via:[TOKEN, KERBEROS]; Host Details : local host is: >>> "ip-10-108-195-141/10.108.195.141"; destination host is: >>> "ip-10-71-51-148":8020; >>> at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:764) >>> at org.apache.hadoop.ipc.Client.call(Client.java:1413) >>> at org.apache.hadoop.ipc.Client.call(Client.java:1362) >>> at >>> org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:206) >>> at com.sun.proxy.$Proxy7.delete(Unknown Source) >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>> at >>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) >>> at >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) >>> at java.lang.reflect.Method.invoke(Method.java:606) >>> at >>> org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:186) >>> at >>> org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102) >>> at com.sun.proxy.$Proxy7.delete(Unknown Source) >>> at >>> org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.delete(ClientNamenodeProtocolTranslatorPB.java:484) >>> at org.apache.hadoop.hdfs.DFSClient.delete(DFSClient.java:1699) >>> at >>> org.apache.hadoop.hdfs.DistributedFileSystem$11.doCall(DistributedFileSystem.java:595) >>> at >>> org.apache.hadoop.hdfs.DistributedFileSystem$11.doCall(DistributedFileSystem.java:591) >>> at >>> org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81) >>> at >>> org.apache.hadoop.hdfs.DistributedFileSystem.delete(DistributedFileSystem.java:591) >>> at >>> org.apache.tez.dag.app.DAGAppMaster.serviceStop(DAGAppMaster.java:1578) >>> at >>> org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221) >>> at >>> org.apache.tez.dag.app.DAGAppMaster$DAGAppMasterShutdownHandler$AMShutdownRunnable.run(DAGAppMaster.java:632) >>> at java.lang.Thread.run(Thread.java:745) >>> Caused by: java.io.IOException: >>> org.apache.hadoop.security.AccessControlException: Client cannot >>> authenticate via:[TOKEN, KERBEROS] >>> at org.apache.hadoop.ipc.Client$Connection$1.run(Client.java:677) >>> at java.security.AccessController.doPrivileged(Native Method) >>> at javax.security.auth.Subject.doAs(Subject.java:415) >>> at >>> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1554) >>> at >>> org.apache.hadoop.ipc.Client$Connection.handleSaslConnectionFailure(Client.java:640) >>> at >>> org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:724) >>> at org.apache.hadoop.ipc.Client$Connection.access$2800(Client.java:367) >>> at org.apache.hadoop.ipc.Client.getConnection(Client.java:1461) >>> at org.apache.hadoop.ipc.Client.call(Client.java:1380) >>> ... 20 more >>> Caused by: org.apache.hadoop.security.AccessControlException: Client cannot >>> authenticate via:[TOKEN, KERBEROS] >>> at >>> org.apache.hadoop.security.SaslRpcClient.selectSaslClient(SaslRpcClient.java:170) >>> at >>> org.apache.hadoop.security.SaslRpcClient.saslConnect(SaslRpcClient.java:393) >>> at >>> org.apache.hadoop.ipc.Client$Connection.setupSaslConnection(Client.java:550) >>> at org.apache.hadoop.ipc.Client$Connection.access$1800(Client.java:367) >>> at org.apache.hadoop.ipc.Client$Connection$2.run(Client.java:716) >>> at org.apache.hadoop.ipc.Client$Connection$2.run(Client.java:712) >>> at java.security.AccessController.doPrivileged(Native Method) >>> at javax.security.auth.Subject.doAs(Subject.java:415) >>> at >>> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1554) >>> at >>> org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:711) >>> ... 23 more >>> 2015-01-14 17:05:49,166 INFO [Thread-1] >>> org.apache.tez.dag.app.DAGAppMaster: The shutdown handler has completed >>> 2015-01-14 17:05:49,167 INFO [AMShutdownThread] >>> org.apache.tez.dag.app.DAGAppMaster: Exiting DAGAppMaster..GoodBye! >>> ———————————————————————————————————————— >>> >>> >>> Also i see this very often, not sure if related: >>> ———————————————————————————————————————— >>> 2015-01-14 17:16:08,793 WARN [AMShutdownThread] >>> org.apache.tez.dag.history.recovery.RecoveryService: Error when closing >>> summary stream >>> org.apache.hadoop.ipc.RemoteException(org.apache.hadoop.hdfs.server.namenode.LeaseExpiredException): >>> No lease on >>> /user/albert/temp/job-22/staging/.tez/application_1421233109369_0019/recovery/1/summary >>> (inode 17605): File does not exist. Holder >>> DFSClient_NONMAPREDUCE_813708729_1 does not have any open files. >>> at >>> org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:2991) >>> at >>> org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFileInternal(FSNamesystem.java:3077) >>> at >>> org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFile(FSNamesystem.java:3047) >>> at >>> org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.complete(NameNodeRpcServer.java:628) >>> at >>> org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.complete(ClientNamenodeProtocolServerSideTranslatorPB.java:484) >>> at >>> org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java) >>> at >>> org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:585) >>> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1026) >>> at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1986) >>> at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1982) >>> at java.security.AccessController.doPrivileged(Native Method) >>> at javax.security.auth.Subject.doAs(Subject.java:415) >>> at >>> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1554) >>> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1980) >>> >>> at org.apache.hadoop.ipc.Client.call(Client.java:1409) >>> at org.apache.hadoop.ipc.Client.call(Client.java:1362) >>> at >>> org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:206) >>> at com.sun.proxy.$Proxy7.complete(Unknown Source) >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>> at >>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) >>> at >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) >>> at java.lang.reflect.Method.invoke(Method.java:606) >>> at >>> org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:186) >>> at >>> org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102) >>> at com.sun.proxy.$Proxy7.complete(Unknown Source) >>> at >>> org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.complete(ClientNamenodeProtocolTranslatorPB.java:406) >>> at >>> org.apache.hadoop.hdfs.DFSOutputStream.completeFile(DFSOutputStream.java:2116) >>> at >>> org.apache.hadoop.hdfs.DFSOutputStream.close(DFSOutputStream.java:2100) >>> at >>> org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:70) >>> at >>> org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:103) >>> at >>> org.apache.tez.dag.history.recovery.RecoveryService.serviceStop(RecoveryService.java:201) >>> at >>> org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221) >>> at >>> org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52) >>> at >>> org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80) >>> at >>> org.apache.hadoop.service.CompositeService.stop(CompositeService.java:158) >>> at >>> org.apache.hadoop.service.CompositeService.serviceStop(CompositeService.java:132) >>> at >>> org.apache.tez.dag.history.HistoryEventHandler.serviceStop(HistoryEventHandler.java:80) >>> at >>> org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221) >>> at >>> org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52) >>> at >>> org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80) >>> at >>> org.apache.tez.dag.app.DAGAppMaster.stopServices(DAGAppMaster.java:1429) >>> at >>> org.apache.tez.dag.app.DAGAppMaster.serviceStop(DAGAppMaster.java:1561) >>> at >>> org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221) >>> at >>> org.apache.tez.dag.app.DAGAppMaster$DAGAppMasterShutdownHandler$AMShutdownRunnable.run(DAGAppMaster.java:632) >>> at java.lang.Thread.run(Thread.java:745) >>> ———————————————————————————————————————— >>> >>> Any ideas what the issue may be ? >>> >>> Thanks >>> Johannes >> >
