Alluxio on Yarn: Workers.size != CoreInstance.size

54 views

Skip to first unread message

Dan

unread,

Jan 12, 2017, 1:42:46 PM1/12/17

to Alluxio Users

Hello,

I'm running an EMR cluster and I'm unable to consistently launch an Alluxio worker on every Core Instance.

My Environment is as follows:

AWS EMR Cluster

EMR Version: emr-5.1.0

EMR Applications: Hive, Ganglia, Spark

Master Instance: r3.xlarge

Core Instances: r3.xlarge (4x)

Alluxio Version: 1.3.0 with PR https://github.com/Alluxio/alluxio/pull/4451 (-Dhadoop.version=2.7.2 -Dspark.version=2.0.1 -Pyarn)

Hadoop Version: 2.7.3-amzn-0

OS: Amazon Linux (based off of RHEL)

Java Version: openjdk version "1.8.0_111"

When I attempt to run `${ALLUXIO_HOME}/integration/bin/alluxio-yarn.sh 4 hdfs://${masterDNS}:8020/opt/alluxio ${masterDNS}` on the Master instance, I see the ApplicationMaster launch, try 2 attempts, and then Fail. It is worth noting that *sometimes* it will work but usually not; it's not consistent. However if I launch with 3 workers it will work 100% of the time.

Worker logs are never created on the nodes and I don't see any errors on the Core Instance node's yarn logs. Can someone point me in the right direction as to what is causing the nodes to be allocated?

See log entries below.

Thanks,

Dan

ip-10-253-194-78.ec2.internal:8042/logs/containers/application_1484236645296_0006/container_1484236645296_0006_01_000001/stdout:

Launching Application Master

2017-01-12 17:22:44,676 INFO type (ApplicationMaster.java:main) - Starting Application Master with args [-num_workers, 4, -master_address, ip-10-253-194-106.ec.internal, -resource_path, hdfs://ip-10-253-194-106.ec.internal:8020/opt/alluxio]

2017-01-12 17:22:44,815 DEBUG Shell (Shell.java:isSetsidSupported) - setsid exited with exit code 0

2017-01-12 17:22:44,876 DEBUG MutableMetricsFactory (MutableMetricsFactory.java:newForField) - 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)])

2017-01-12 17:22:44,891 DEBUG MutableMetricsFactory (MutableMetricsFactory.java:newForField) - 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)])

2017-01-12 17:22:44,891 DEBUG MutableMetricsFactory (MutableMetricsFactory.java:newForField) - 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])

2017-01-12 17:22:44,892 DEBUG MetricsSystemImpl (MetricsSystemImpl.java:register) - UgiMetrics, User and group related metrics

2017-01-12 17:22:45,142 DEBUG KerberosName (KerberosName.java:<clinit>) - Kerberos krb5 configuration not found, setting default realm to empty

2017-01-12 17:22:45,145 DEBUG Groups (Groups.java:getUserToGroupsMappingService) - Creating new Groups object

2017-01-12 17:22:45,147 DEBUG NativeCodeLoader (NativeCodeLoader.java:<clinit>) - Trying to load the custom-built native-hadoop library...

2017-01-12 17:22:45,148 DEBUG NativeCodeLoader (NativeCodeLoader.java:<clinit>) - Loaded the native-hadoop library

2017-01-12 17:22:45,149 DEBUG JniBasedUnixGroupsMapping (JniBasedUnixGroupsMapping.java:<clinit>) - Using JniBasedUnixGroupsMapping for Group resolution

2017-01-12 17:22:45,149 DEBUG JniBasedUnixGroupsMappingWithFallback (JniBasedUnixGroupsMappingWithFallback.java:<init>) - Group mapping impl=org.apache.hadoop.security.JniBasedUnixGroupsMapping

2017-01-12 17:22:45,250 DEBUG Groups (Groups.java:<init>) - Group mapping impl=org.apache.hadoop.security.JniBasedUnixGroupsMappingWithFallback; cacheTimeout=300000; warningDeltaMs=5000

2017-01-12 17:22:45,289 DEBUG type (NetworkAddressUtils.java:getLocalIpAddress) - address: ip-10-253-194-78.ec.internal/10.253.194.78 isLoopbackAddress: false, with host 10.253.194.78 ip-10-253-194-78.ec.internal

2017-01-12 17:22:45,294 DEBUG InternalLoggerFactory (Slf4JLogger.java:debug) - Using SLF4J as the default logging framework

2017-01-12 17:22:45,298 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - java.nio.Buffer.address: available

2017-01-12 17:22:45,300 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - sun.misc.Unsafe.theUnsafe: available

2017-01-12 17:22:45,301 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - sun.misc.Unsafe.copyMemory: available

2017-01-12 17:22:45,301 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - java.nio.Bits.unaligned: true

2017-01-12 17:22:45,302 DEBUG PlatformDependent (Slf4JLogger.java:debug) - Java version: 8

2017-01-12 17:22:45,302 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.noUnsafe: false

2017-01-12 17:22:45,302 DEBUG PlatformDependent (Slf4JLogger.java:debug) - sun.misc.Unsafe: available

2017-01-12 17:22:45,303 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.noJavassist: false

2017-01-12 17:22:45,359 DEBUG PlatformDependent (Slf4JLogger.java:debug) - Javassist: available

2017-01-12 17:22:45,359 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)

2017-01-12 17:22:45,359 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.bitMode: 64 (sun.arch.data.model)

2017-01-12 17:22:45,360 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.noPreferDirect: false

2017-01-12 17:22:45,360 DEBUG NativeLibraryLoader (Slf4JLogger.java:debug) - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)

2017-01-12 17:22:45,361 DEBUG NativeLibraryLoader (Slf4JLogger.java:debug) - -Dio.netty.netty.workdir: /tmp (io.netty.tmpdir)

2017-01-12 17:22:45,376 DEBUG NetUtil (Slf4JLogger.java:debug) - Loopback interface: lo (lo, 127.0.0.1)

2017-01-12 17:22:45,377 DEBUG NetUtil (Slf4JLogger.java:debug) - /proc/sys/net/core/somaxconn: 4096

2017-01-12 17:22:45,405 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.impl.NMClientImpl entered state INITED

2017-01-12 17:22:45,439 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:<init>) - yarn.client.max-cached-nodemanagers-proxies : 0

2017-01-12 17:22:45,468 DEBUG YarnRPC (YarnRPC.java:create) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC

2017-01-12 17:22:45,469 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.impl.NMClientImpl is started

2017-01-12 17:22:45,469 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.async.AMRMClientAsync entered state INITED

2017-01-12 17:22:45,469 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.impl.AMRMClientImpl entered state INITED

2017-01-12 17:22:45,484 DEBUG UserGroupInformation (UserGroupInformation.java:login) - hadoop login

2017-01-12 17:22:45,485 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - hadoop login commit

2017-01-12 17:22:45,489 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - using local user:UnixPrincipal: yarn

2017-01-12 17:22:45,489 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - Using user: "UnixPrincipal: yarn" with name yarn

2017-01-12 17:22:45,489 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - User entry: "yarn"

2017-01-12 17:22:45,497 DEBUG UserGroupInformation (UserGroupInformation.java:loginUserFromSubject) - UGI loginUser:yarn (auth:SIMPLE)

2017-01-12 17:22:45,504 INFO RMProxy (RMProxy.java:createRMProxy) - Connecting to ResourceManager at ip-10-253-194-106.ec.internal/10.253.194.106:8030

2017-01-12 17:22:45,505 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.yarn.client.RMProxy.getProxy(RMProxy.java:136)

2017-01-12 17:22:45,506 DEBUG YarnRPC (YarnRPC.java:create) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC

2017-01-12 17:22:45,506 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ApplicationMasterProtocol

2017-01-12 17:22:45,532 DEBUG Server (Server.java:registerProtocolEngine) - rpcKind=RPC_PROTOCOL_BUFFER, rpcRequestWrapperClass=class org.apache.hadoop.ipc.ProtobufRpcEngine$RpcRequestWrapper, rpcInvoker=org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker@50ad3bc1

2017-01-12 17:22:45,540 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@101952da

2017-01-12 17:22:45,566 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.impl.AMRMClientImpl is started

2017-01-12 17:22:45,566 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.async.AMRMClientAsync is started

2017-01-12 17:22:45,566 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state INITED

2017-01-12 17:22:45,566 INFO RMProxy (RMProxy.java:createRMProxy) - Connecting to ResourceManager at ip-10-253-194-106.ec.internal/10.253.194.106:8032

2017-01-12 17:22:45,567 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.yarn.client.RMProxy.getProxy(RMProxy.java:136)

2017-01-12 17:22:45,567 DEBUG YarnRPC (YarnRPC.java:create) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC

2017-01-12 17:22:45,567 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ApplicationClientProtocol

2017-01-12 17:22:45,578 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@101952da

2017-01-12 17:22:45,647 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.impl.YarnClientImpl is started

2017-01-12 17:22:45,706 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 17:22:45,706 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-106.ec.internal/10.253.194.106:8030

2017-01-12 17:22:45,717 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 17:22:45,770 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 17:22:45,777 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 17:22:45,784 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ApplicationMasterProtocolPB info:org.apache.hadoop.yarn.security.SchedulerSecurityInfo$1@73a8da0f

2017-01-12 17:22:45,785 DEBUG AMRMTokenSelector (AMRMTokenSelector.java:selectToken) - Looking for a token with service 10.253.194.106:8030

2017-01-12 17:22:45,785 DEBUG AMRMTokenSelector (AMRMTokenSelector.java:selectToken) - Token kind is YARN_AM_RM_TOKEN and the token's service name is 10.253.194.106:8030

2017-01-12 17:22:45,789 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 17:22:45,804 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ApplicationMasterProtocolPB

2017-01-12 17:22:45,806 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgGELDHl5uZKxABEPC1+OQG

2017-01-12 17:22:45,806 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 17:22:45,806 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 17:22:45,808 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 17:22:45,810 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 17:22:45,810 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 17:22:45,815 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn: starting, having connections 1

2017-01-12 17:22:45,816 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn sending #0

2017-01-12 17:22:45,819 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn got value #0

2017-01-12 17:22:45,819 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: registerApplicationMaster took 136ms

2017-01-12 17:22:45,825 INFO type (ApplicationMaster.java:start) - ApplicationMaster registered

2017-01-12 17:22:45,825 INFO type (ApplicationMaster.java:masterExists) - Checking for master at: http://ip-10-253-194-106.ec.internal:19999/v1/api/master/version

2017-01-12 17:22:45,837 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn sending #1

2017-01-12 17:22:45,841 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn got value #1

2017-01-12 17:22:45,844 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 8ms

2017-01-12 17:22:45,845 INFO type (ApplicationMaster.java:masterExists) - Response code from master was: 200

2017-01-12 17:22:45,847 INFO type (ApplicationMaster.java:requestAndLaunchContainers) - Found master already running on ip-10-253-194-106.ec.internal

2017-01-12 17:22:45,851 INFO type (ContainerAllocator.java:requestContainers) - Requesting 4 worker containers

2017-01-12 17:22:45,864 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 17:22:45,865 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-106.ec.internal/10.253.194.106:8032

2017-01-12 17:22:45,865 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 17:22:45,866 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 17:22:45,867 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

auths {

method: "SIMPLE"

mechanism: ""

}

2017-01-12 17:22:45,868 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ApplicationClientProtocolPB info:org.apache.hadoop.yarn.security.client.ClientRMSecurityInfo$2@481ba2cf

2017-01-12 17:22:45,868 DEBUG RMDelegationTokenSelector (RMDelegationTokenSelector.java:selectToken) - Looking for a token with service 10.253.194.106:8032

2017-01-12 17:22:45,869 DEBUG RMDelegationTokenSelector (RMDelegationTokenSelector.java:selectToken) - Token kind is YARN_AM_RM_TOKEN and the token's service name is 10.253.194.106:8030

2017-01-12 17:22:45,870 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use SIMPLE authentication for protocol ApplicationClientProtocolPB

2017-01-12 17:22:45,871 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

auths {

method: "SIMPLE"

mechanism: ""

}

2017-01-12 17:22:45,872 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn: starting, having connections 2

2017-01-12 17:22:45,872 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn sending #2

2017-01-12 17:22:45,874 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn got value #2

2017-01-12 17:22:45,874 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 10ms

2017-01-12 17:22:45,889 INFO type (ContainerAllocator.java:requestContainers) - Making 4 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-78.ec.internal, ip-10-253-194-54.ec.internal, ip-10-253-194-157.ec.internal, ip-10-253-194-179.ec.internal]

2017-01-12 17:22:45,889 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-78.ec.internal to /default-rack

2017-01-12 17:22:45,890 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-54.ec.internal to /default-rack

2017-01-12 17:22:45,891 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-157.ec.internal to /default-rack

2017-01-12 17:22:45,891 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-179.ec.internal to /default-rack

2017-01-12 17:22:45,892 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - Added priority=101

2017-01-12 17:22:45,896 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-179.ec.internal numContainers=1 #asks=1

2017-01-12 17:22:45,896 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=1 #asks=5

2017-01-12 17:22:45,897 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=1 #asks=6

2017-01-12 17:22:45,897 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-78.ec.internal to /default-rack

2017-01-12 17:22:45,897 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-54.ec.internal to /default-rack

2017-01-12 17:22:45,897 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-157.ec.internal to /default-rack

2017-01-12 17:22:45,897 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-179.ec.internal to /default-rack

2017-01-12 17:22:45,898 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-179.ec.internal numContainers=2 #asks=6

2017-01-12 17:22:45,898 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=2 #asks=6

2017-01-12 17:22:45,898 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=2 #asks=6

2017-01-12 17:22:45,898 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-78.ec.internal to /default-rack

2017-01-12 17:22:45,899 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-54.ec.internal to /default-rack

2017-01-12 17:22:45,899 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-157.ec.internal to /default-rack

2017-01-12 17:22:45,899 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-179.ec.internal to /default-rack

2017-01-12 17:22:45,899 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-179.ec.internal numContainers=3 #asks=6

2017-01-12 17:22:45,900 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-157.ec.internal numContainers=3 #asks=6

2017-01-12 17:22:45,900 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=3 #asks=6

2017-01-12 17:22:45,900 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=3 #asks=6

2017-01-12 17:22:45,900 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-78.ec.internal to /default-rack

2017-01-12 17:22:45,900 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-54.ec.internal to /default-rack

2017-01-12 17:22:45,900 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-157.ec.internal to /default-rack

2017-01-12 17:22:45,901 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-179.ec.internal to /default-rack

2017-01-12 17:22:45,901 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-179.ec.internal numContainers=4 #asks=6

2017-01-12 17:22:45,901 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=4 #asks=6

2017-01-12 17:22:45,902 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=4 #asks=6

2017-01-12 17:22:46,368 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn sending #3

2017-01-12 17:22:46,370 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn got value #3

2017-01-12 17:22:46,370 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 3ms

2017-01-12 17:22:46,871 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn sending #4

2017-01-12 17:22:46,878 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn got value #4

2017-01-12 17:22:46,879 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 8ms

2017-01-12 17:22:46,881 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-78.ec.internal:8041

2017-01-12 17:22:46,881 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-179.ec.internal:8041

2017-01-12 17:22:46,883 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-78.ec.internal

2017-01-12 17:22:46,887 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-179.ec.internal

2017-01-12 17:22:46,887 INFO type (ContainerAllocator.java:requestContainers) - Requesting 2 worker containers

2017-01-12 17:22:46,888 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn sending #5

2017-01-12 17:22:46,889 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn got value #5

2017-01-12 17:22:46,889 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 1ms

2017-01-12 17:22:46,889 INFO type (ContainerAllocator.java:requestContainers) - Making 2 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-54.ec.internal, ip-10-253-194-157.ec.internal]

2017-01-12 17:22:46,890 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-54.ec.internal to /default-rack

2017-01-12 17:22:46,890 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-157.ec.internal to /default-rack

2017-01-12 17:22:46,890 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-54.ec.internal numContainers=5 #asks=1

2017-01-12 17:22:46,890 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=5 #asks=3

2017-01-12 17:22:46,890 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=5 #asks=4

2017-01-12 17:22:46,890 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-54.ec.internal to /default-rack

2017-01-12 17:22:46,890 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-157.ec.internal to /default-rack

2017-01-12 17:22:46,891 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-54.ec.internal numContainers=6 #asks=4

2017-01-12 17:22:46,891 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=6 #asks=4

2017-01-12 17:22:46,891 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=6 #asks=4

2017-01-12 17:22:47,383 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn sending #6

2017-01-12 17:22:47,387 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn got value #6

2017-01-12 17:22:47,388 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 5ms

2017-01-12 17:22:47,391 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484236645296_0006_01_000003

2017-01-12 17:22:47,391 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484236645296_0006_01_000006

2017-01-12 17:22:47,891 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn sending #7

2017-01-12 17:22:47,898 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8030 from yarn got value #7

2017-01-12 17:22:47,898 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 8ms

2017-01-12 17:22:47,898 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-157.ec.internal:8041

2017-01-12 17:22:47,899 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-78.ec.internal

2017-01-12 17:22:47,899 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-179.ec.internal

2017-01-12 17:22:47,899 INFO type (ContainerAllocator.java:requestContainers) - Requesting 2 worker containers

2017-01-12 17:22:47,899 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-157.ec.internal

2017-01-12 17:22:47,899 DEBUG Client (Client.java:run) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn sending #8

2017-01-12 17:22:47,901 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (797814020) connection to ip-10-253-194-106.ec.internal/10.253.194.106:8032 from yarn got value #8

2017-01-12 17:22:47,901 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 2ms

2017-01-12 17:22:47,905 ERROR type (ApplicationMaster.java:main) - Error running Application Master

java.lang.RuntimeException: Not enough usable hosts in the cluster to launch 2 worker containers. Only 1 hosts available

at alluxio.yarn.ContainerAllocator.requestContainers(ContainerAllocator.java:158)

at alluxio.yarn.ContainerAllocator.allocateContainers(ContainerAllocator.java:110)

at alluxio.yarn.ApplicationMaster.requestAndLaunchContainers(ApplicationMaster.java:341)

at alluxio.yarn.ApplicationMaster.runApplicationMaster(ApplicationMaster.java:233)

at alluxio.yarn.ApplicationMaster.main(ApplicationMaster.java:211)

ip-10-253-194-78.ec.internal:8042/logs/yarn-yarn-nodemanager-ip-10-253-194-78.log:

2017-01-12 17:22:43,491 INFO SecurityLogger.org.apache.hadoop.ipc.Server (Socket Reader #1 for port 8041): Auth successful for appattempt_1484236645296_0006_000001 (auth:SIMPLE)

2017-01-12 17:22:43,511 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (IPC Server handler 29 on 8041): Start request for container_1484236645296_0006_01_000001 by user hadoop

2017-01-12 17:22:43,511 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (IPC Server handler 29 on 8041): Creating a new application reference for app application_1484236645296_0006

2017-01-12 17:22:43,511 INFO org.apache.hadoop.yarn.server.nodemanager.NMAuditLogger (IPC Server handler 29 on 8041): USER=hadoop IP=10.253.194.106 OPERATION=Start Container Request TARGET=ContainerManageImpl RESULT=SUCCESS APPID=application_1484236645296_0006 CONTAINERID=container_1484236645296_0006_01_000001

2017-01-12 17:22:43,511 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.application.ApplicationImpl (AsyncDispatcher event handler): Application application_1484236645296_0006 transitioned from NEW to INITING

2017-01-12 17:22:43,511 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.application.ApplicationImpl (AsyncDispatcher event handler): Adding container_1484236645296_0006_01_000001 to application application_1484236645296_0006

2017-01-12 17:22:43,515 WARN org.apache.hadoop.yarn.server.nodemanager.containermanager.logaggregation.AppLogAggregatorImpl (AsyncDispatcher event handler): rollingMonitorInterval is set as -1. The log rolling mornitoring interval is disabled. The logs will be aggregated after this application is finished.

2017-01-12 17:22:43,521 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.application.ApplicationImpl (AsyncDispatcher event handler): Application application_1484236645296_0006 transitioned from INITING to RUNNING

2017-01-12 17:22:43,521 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl (AsyncDispatcher event handler): Container container_1484236645296_0006_01_000001 transitioned from NEW to LOCALIZING

2017-01-12 17:22:43,521 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.AuxServices (AsyncDispatcher event handler): Got event CONTAINER_INIT for appId application_1484236645296_0006

2017-01-12 17:22:43,521 INFO org.apache.spark.network.yarn.YarnShuffleService (AsyncDispatcher event handler): Initializing container container_1484236645296_0006_01_000001

2017-01-12 17:22:43,522 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.LocalizedResource (AsyncDispatcher event handler): Resource hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio.jar transitioned from INIT to DOWNLOADING

2017-01-12 17:22:43,522 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.ResourceLocalizationService (AsyncDispatcher event handler): Downloading public rsrc:{ hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio.jar, 1484241751585, FILE, null }

2017-01-12 17:22:43,533 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.ResourceLocalizationService (AsyncDispatcher event handler): Downloading public rsrc:{ hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio.tar.gz, 1484241748857, FILE, null }

2017-01-12 17:22:43,542 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.ResourceLocalizationService (AsyncDispatcher event handler): Downloading public rsrc:{ hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio-yarn-setup.sh, 1484241753998, FILE, null }

2017-01-12 17:22:43,587 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.LocalizedResource (Public Localizer): Resource hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio-yarn-setup.sh(->/mnt/yarn/filecache/18/alluxio-yarn-setup.sh) transitioned from DOWNLOADING to LOCALIZED

2017-01-12 17:22:43,747 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.LocalizedResource (Public Localizer): Resource hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio.tar.gz(->/mnt/yarn/filecache/17/alluxio.tar.gz) transitioned from DOWNLOADING to LOCALIZED

2017-01-12 17:22:43,758 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.LocalizedResource (Public Localizer): Resource hdfs://ip-10-253-194-106.ec2.internal:8020/opt/alluxio/alluxio.jar(->/mnt/yarn/filecache/16/alluxio.jar) transitioned from DOWNLOADING to LOCALIZED

2017-01-12 17:22:43,759 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl (AsyncDispatcher event handler): Container container_1484236645296_0006_01_000001 transitioned from LOCALIZING to LOCALIZED

2017-01-12 17:22:43,778 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl (AsyncDispatcher event handler): Container container_1484236645296_0006_01_000001 transitioned from LOCALIZED to RUNNING

2017-01-12 17:22:43,782 INFO org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor (ContainersLauncher #2): launchContainer: [bash, /mnt/yarn/usercache/hadoop/appcache/application_1484236645296_0006/container_1484236645296_0006_01_000001/default_container_executor.sh]

2017-01-12 17:22:46,355 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl (Container Monitor): Starting resource-monitoring for container_1484236645296_0006_01_000001

2017-01-12 17:22:46,371 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl (Container Monitor): Memory usage of ProcessTree 23306 for container-id container_1484236645296_0006_01_000001: 169.5 MB of 2 GB physical memory used; 2.3 GB of 10 GB virtual memory used

2017-01-12 17:22:47,487 WARN org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (AsyncDispatcher event handler): Event EventType: KILL_CONTAINER sent to absent container container_1484236645296_0006_01_000003

2017-01-12 17:22:47,926 WARN org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor (ContainersLauncher #2): Exit code from container container_1484236645296_0006_01_000001 is : 1

2017-01-12 17:22:47,926 WARN org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor (ContainersLauncher #2): Exception from container-launch with container ID: container_1484236645296_0006_01_000001 and exit code: 1

ExitCodeException exitCode=1:

at org.apache.hadoop.util.Shell.runCommand(Shell.java:582)

at org.apache.hadoop.util.Shell.run(Shell.java:479)

at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:773)

at org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor.launchContainer(DefaultContainerExecutor.java:212)

at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:302)

at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:82)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

2017-01-12 17:22:47,926 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): Exception from container-launch.

2017-01-12 17:22:47,926 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): Container id: container_1484236645296_0006_01_000001

2017-01-12 17:22:47,926 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): Exit code: 1

2017-01-12 17:22:47,926 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): Stack trace: ExitCodeException exitCode=1:

2017-01-12 17:22:47,926 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at org.apache.hadoop.util.Shell.runCommand(Shell.java:582)

2017-01-12 17:22:47,926 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at org.apache.hadoop.util.Shell.run(Shell.java:479)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:773)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor.launchContainer(DefaultContainerExecutor.java:212)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:302)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:82)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at java.util.concurrent.FutureTask.run(FutureTask.java:266)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.ContainerExecutor (ContainersLauncher #2): at java.lang.Thread.run(Thread.java:745)

2017-01-12 17:22:47,927 WARN org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch (ContainersLauncher #2): Container exited with a non-zero exit code 1

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl (AsyncDispatcher event handler): Container container_1484236645296_0006_01_000001 transitioned from RUNNING to EXITED_WITH_FAILURE

2017-01-12 17:22:47,927 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch (AsyncDispatcher event handler): Cleaning up container container_1484236645296_0006_01_000001

2017-01-12 17:22:47,943 INFO org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor (DeletionService #2): Deleting absolute path : /mnt/yarn/usercache/hadoop/appcache/application_1484236645296_0006/container_1484236645296_0006_01_000001

2017-01-12 17:22:47,944 WARN org.apache.hadoop.yarn.server.nodemanager.NMAuditLogger (AsyncDispatcher event handler): USER=hadoop OPERATION=Container Finished - Failed TARGET=ContainerImpl RESULT=FAILURE DESCRIPTION=Container failed with state: EXITED_WITH_FAILURE APPID=application_1484236645296_0006 CONTAINERID=container_1484236645296_0006_01_000001

2017-01-12 17:22:47,944 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl (AsyncDispatcher event handler): Container container_1484236645296_0006_01_000001 transitioned from EXITED_WITH_FAILURE to DONE

2017-01-12 17:22:47,944 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.application.ApplicationImpl (AsyncDispatcher event handler): Removing container_1484236645296_0006_01_000001 from application application_1484236645296_0006

2017-01-12 17:22:47,944 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.logaggregation.AppLogAggregatorImpl (AsyncDispatcher event handler): Considering container container_1484236645296_0006_01_000001 for log-aggregation

2017-01-12 17:22:47,945 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.AuxServices (AsyncDispatcher event handler): Got event CONTAINER_STOP for appId application_1484236645296_0006

2017-01-12 17:22:47,945 INFO org.apache.spark.network.yarn.YarnShuffleService (AsyncDispatcher event handler): Stopping container container_1484236645296_0006_01_000001

2017-01-12 17:22:47,960 INFO SecurityLogger.org.apache.hadoop.ipc.Server (Socket Reader #1 for port 8041): Auth successful for appattempt_1484236645296_0006_000001 (auth:SIMPLE)

2017-01-12 17:22:47,963 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (IPC Server handler 7 on 8041): Stopping container with container Id: container_1484236645296_0006_01_000001

2017-01-12 17:22:47,963 INFO org.apache.hadoop.yarn.server.nodemanager.NMAuditLogger (IPC Server handler 7 on 8041): USER=hadoop IP=10.253.194.106 OPERATION=Stop Container Request TARGET=ContainerManageImpl RESULT=SUCCESS APPID=application_1484236645296_0006 CONTAINERID=container_1484236645296_0006_01_000001

2017-01-12 17:22:48,947 INFO org.apache.hadoop.yarn.server.nodemanager.NodeStatusUpdaterImpl (Node Status Updater): Removed completed containers from NM context: [container_1484236645296_0006_01_000001]

2017-01-12 17:22:48,947 WARN org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (AsyncDispatcher event handler): Event EventType: KILL_CONTAINER sent to absent container container_1484236645296_0006_01_000002

2017-01-12 17:22:49,371 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl (Container Monitor): Stopping resource-monitoring for container_1484236645296_0006_01_000001

2017-01-12 17:22:54,951 WARN org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (AsyncDispatcher event handler): Event EventType: KILL_CONTAINER sent to absent container container_1484236645296_0006_02_000018

2017-01-12 17:22:54,952 WARN org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl (AsyncDispatcher event handler): Event EventType: KILL_CONTAINER sent to absent container container_1484236645296_0006_02_000020

2017-01-12 17:22:54,952 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.application.ApplicationImpl (AsyncDispatcher event handler): Application application_1484236645296_0006 transitioned from RUNNING to APPLICATION_RESOURCES_CLEANINGUP

2017-01-12 17:22:54,952 INFO org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor (DeletionService #1): Deleting absolute path : /mnt/yarn/usercache/hadoop/appcache/application_1484236645296_0006

2017-01-12 17:22:54,952 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.AuxServices (AsyncDispatcher event handler): Got event APPLICATION_STOP for appId application_1484236645296_0006

2017-01-12 17:22:54,952 INFO org.apache.spark.network.yarn.YarnShuffleService (AsyncDispatcher event handler): Stopping application application_1484236645296_0006

2017-01-12 17:22:54,952 INFO org.apache.spark.network.shuffle.ExternalShuffleBlockResolver (AsyncDispatcher event handler): Application application_1484236645296_0006 removed, cleanupLocalDirs = false

2017-01-12 17:22:54,952 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.logaggregation.AppLogAggregatorImpl (AsyncDispatcher event handler): Application just finished : application_1484236645296_0006

2017-01-12 17:22:54,953 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.logaggregation.AppLogAggregatorImpl (LogAggregationService #2): remote log file /var/log/hadoop-yarn/apps/hadoop/logs/application_1484236645296_0006/ip-10-253-194-78.ec2.internal_8041 is not directWriteable, writing logs to /var/log/hadoop-yarn/apps/hadoop/logs/application_1484236645296_0006/ip-10-253-194-78.ec2.internal_8041.tmp

2017-01-12 17:22:54,960 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.logaggregation.AppLogAggregatorImpl (LogAggregationService #2): Uploading logs for container container_1484236645296_0006_01_000001. Current good log dirs are /var/log/hadoop-yarn/containers

2017-01-12 17:22:54,973 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.logaggregation.AppLogAggregatorImpl (LogAggregationService #2): renaming /var/log/hadoop-yarn/apps/hadoop/logs/application_1484236645296_0006/ip-10-253-194-78.ec2.internal_8041.tmp to /var/log/hadoop-yarn/apps/hadoop/logs/application_1484236645296_0006/ip-10-253-194-78.ec2.internal_8041

Andrew Audibert

unread,

Jan 12, 2017, 2:56:08 PM1/12/17

to Dan, Alluxio Users

Hi Dan,

Could you try changing the code in ContainerAllocator#requestContainers to check

if (hosts.length * mMaxContainersPerHost < mTargetNumContainers - mAllocatedContainers.size()) {

instead of

if (hosts.length * mMaxContainersPerHost < numContainersToRequest) {

This looks like a race condition where the number of containers allocated so far is stale, so the system thinks there aren't enough available hosts to reach the requested number of workers. I've created a ticket to track it: https://alluxio.atlassian.net/browse/ALLUXIO-2519

Hope that helps,
Andrew

--
You received this message because you are subscribed to the Google Groups "Alluxio Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to alluxio-user...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Dan

unread,

Jan 12, 2017, 4:15:30 PM1/12/17

to Alluxio Users, max...@gmail.com

Hi Andrew,

Thanks for the quick response! That seems to have worked. Upon EMR standup, the first attempt seemed to not have worked using my bootstrap script. The AM was "RUNNING" but I never saw Workers in the Alluxio UI. So I killed the AM and tried launching again with 4; repeated this 3 times and all were successful. I then increased the test bed to 8 Core Instances and 8 Workers which worked both times I tried it. The only thing to note is that it seems to take a little bit longer to bring the workers up. I've included the AM log output for your review below. I am going to try a clean EMR standup once more and if successful, I will create a PR with the changes.

Thanks,

Dan

Launching Application Master

2017-01-12 21:00:54,314 INFO type (ApplicationMaster.java:main) - Starting Application Master with args [-num_workers, 8, -master_address, ip-10-253-194-85.ec2.internal, -resource_path, hdfs://ip-10-253-194-85.ec2.internal:8020/opt/alluxio]

2017-01-12 21:00:54,455 DEBUG Shell (Shell.java:isSetsidSupported) - setsid exited with exit code 0

2017-01-12 21:00:54,514 DEBUG MutableMetricsFactory (MutableMetricsFactory.java:newForField) - 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)])

2017-01-12 21:00:54,529 DEBUG MutableMetricsFactory (MutableMetricsFactory.java:newForField) - 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)])

2017-01-12 21:00:54,530 DEBUG MutableMetricsFactory (MutableMetricsFactory.java:newForField) - 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])

2017-01-12 21:00:54,531 DEBUG MetricsSystemImpl (MetricsSystemImpl.java:register) - UgiMetrics, User and group related metrics

2017-01-12 21:00:54,782 DEBUG KerberosName (KerberosName.java:<clinit>) - Kerberos krb5 configuration not found, setting default realm to empty

2017-01-12 21:00:54,786 DEBUG Groups (Groups.java:getUserToGroupsMappingService) - Creating new Groups object

2017-01-12 21:00:54,788 DEBUG NativeCodeLoader (NativeCodeLoader.java:<clinit>) - Trying to load the custom-built native-hadoop library...

2017-01-12 21:00:54,789 DEBUG NativeCodeLoader (NativeCodeLoader.java:<clinit>) - Loaded the native-hadoop library

2017-01-12 21:00:54,789 DEBUG JniBasedUnixGroupsMapping (JniBasedUnixGroupsMapping.java:<clinit>) - Using JniBasedUnixGroupsMapping for Group resolution

2017-01-12 21:00:54,790 DEBUG JniBasedUnixGroupsMappingWithFallback (JniBasedUnixGroupsMappingWithFallback.java:<init>) - Group mapping impl=org.apache.hadoop.security.JniBasedUnixGroupsMapping

2017-01-12 21:00:54,878 DEBUG Groups (Groups.java:<init>) - Group mapping impl=org.apache.hadoop.security.JniBasedUnixGroupsMappingWithFallback; cacheTimeout=300000; warningDeltaMs=5000

2017-01-12 21:00:54,906 DEBUG type (NetworkAddressUtils.java:getLocalIpAddress) - address: ip-10-253-194-72.ec2.internal/10.253.194.72 isLoopbackAddress: false, with host 10.253.194.72 ip-10-253-194-72.ec2.internal

2017-01-12 21:00:54,912 DEBUG InternalLoggerFactory (Slf4JLogger.java:debug) - Using SLF4J as the default logging framework

2017-01-12 21:00:54,916 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - java.nio.Buffer.address: available

2017-01-12 21:00:54,918 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - sun.misc.Unsafe.theUnsafe: available

2017-01-12 21:00:54,918 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - sun.misc.Unsafe.copyMemory: available

2017-01-12 21:00:54,919 DEBUG PlatformDependent0 (Slf4JLogger.java:debug) - java.nio.Bits.unaligned: true

2017-01-12 21:00:54,921 DEBUG PlatformDependent (Slf4JLogger.java:debug) - Java version: 8

2017-01-12 21:00:54,921 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.noUnsafe: false

2017-01-12 21:00:54,921 DEBUG PlatformDependent (Slf4JLogger.java:debug) - sun.misc.Unsafe: available

2017-01-12 21:00:54,921 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.noJavassist: false

2017-01-12 21:00:54,986 DEBUG PlatformDependent (Slf4JLogger.java:debug) - Javassist: available

2017-01-12 21:00:54,987 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)

2017-01-12 21:00:54,987 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.bitMode: 64 (sun.arch.data.model)

2017-01-12 21:00:54,987 DEBUG PlatformDependent (Slf4JLogger.java:debug) - -Dio.netty.noPreferDirect: false

2017-01-12 21:00:54,989 DEBUG NativeLibraryLoader (Slf4JLogger.java:debug) - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)

2017-01-12 21:00:54,989 DEBUG NativeLibraryLoader (Slf4JLogger.java:debug) - -Dio.netty.netty.workdir: /tmp (io.netty.tmpdir)

2017-01-12 21:00:55,006 DEBUG NetUtil (Slf4JLogger.java:debug) - Loopback interface: lo (lo, 127.0.0.1)

2017-01-12 21:00:55,007 DEBUG NetUtil (Slf4JLogger.java:debug) - /proc/sys/net/core/somaxconn: 4096

2017-01-12 21:00:55,034 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.impl.NMClientImpl entered state INITED

2017-01-12 21:00:55,078 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:<init>) - yarn.client.max-cached-nodemanagers-proxies : 0

2017-01-12 21:00:55,101 DEBUG YarnRPC (YarnRPC.java:create) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC

2017-01-12 21:00:55,102 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.impl.NMClientImpl is started

2017-01-12 21:00:55,102 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.async.AMRMClientAsync entered state INITED

2017-01-12 21:00:55,102 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.impl.AMRMClientImpl entered state INITED

2017-01-12 21:00:55,114 DEBUG UserGroupInformation (UserGroupInformation.java:login) - hadoop login

2017-01-12 21:00:55,115 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - hadoop login commit

2017-01-12 21:00:55,119 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - using local user:UnixPrincipal: yarn

2017-01-12 21:00:55,119 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - Using user: "UnixPrincipal: yarn" with name yarn

2017-01-12 21:00:55,119 DEBUG UserGroupInformation (UserGroupInformation.java:commit) - User entry: "yarn"

2017-01-12 21:00:55,128 DEBUG UserGroupInformation (UserGroupInformation.java:loginUserFromSubject) - UGI loginUser:yarn (auth:SIMPLE)

2017-01-12 21:00:55,135 INFO RMProxy (RMProxy.java:createRMProxy) - Connecting to ResourceManager at ip-10-253-194-85.ec2.internal/10.253.194.85:8030

2017-01-12 21:00:55,135 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.yarn.client.RMProxy.getProxy(RMProxy.java:136)

2017-01-12 21:00:55,136 DEBUG YarnRPC (YarnRPC.java:create) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC

2017-01-12 21:00:55,137 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ApplicationMasterProtocol

2017-01-12 21:00:55,165 DEBUG Server (Server.java:registerProtocolEngine) - rpcKind=RPC_PROTOCOL_BUFFER, rpcRequestWrapperClass=class org.apache.hadoop.ipc.ProtobufRpcEngine$RpcRequestWrapper, rpcInvoker=org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker@223aa2f7

2017-01-12 21:00:55,172 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:00:55,201 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.impl.AMRMClientImpl is started

2017-01-12 21:00:55,201 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.async.AMRMClientAsync is started

2017-01-12 21:00:55,201 DEBUG AbstractService (AbstractService.java:enterState) - Service: org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state INITED

2017-01-12 21:00:55,202 INFO RMProxy (RMProxy.java:createRMProxy) - Connecting to ResourceManager at ip-10-253-194-85.ec2.internal/10.253.194.85:8032

2017-01-12 21:00:55,202 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.yarn.client.RMProxy.getProxy(RMProxy.java:136)

2017-01-12 21:00:55,202 DEBUG YarnRPC (YarnRPC.java:create) - Creating YarnRPC for org.apache.hadoop.yarn.ipc.HadoopYarnProtoRPC

2017-01-12 21:00:55,203 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ApplicationClientProtocol

2017-01-12 21:00:55,217 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:00:55,294 DEBUG AbstractService (AbstractService.java:start) - Service org.apache.hadoop.yarn.client.api.impl.YarnClientImpl is started

2017-01-12 21:00:55,360 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:00:55,360 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-85.ec2.internal/10.253.194.85:8030

2017-01-12 21:00:55,371 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:00:55,427 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:00:55,433 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:00:55,438 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ApplicationMasterProtocolPB info:org.apache.hadoop.yarn.security.SchedulerSecurityInfo$1@6bf08014

2017-01-12 21:00:55,439 DEBUG AMRMTokenSelector (AMRMTokenSelector.java:selectToken) - Looking for a token with service 10.253.194.85:8030

2017-01-12 21:00:55,439 DEBUG AMRMTokenSelector (AMRMTokenSelector.java:selectToken) - Token kind is YARN_AM_RM_TOKEN and the token's service name is 10.253.194.85:8030

2017-01-12 21:00:55,444 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:00:55,464 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ApplicationMasterProtocolPB

2017-01-12 21:00:55,466 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEJLy57r7/////wE=

2017-01-12 21:00:55,466 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:00:55,466 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:00:55,468 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:00:55,469 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:00:55,470 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:00:55,474 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn: starting, having connections 1

2017-01-12 21:00:55,476 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #0

2017-01-12 21:00:55,479 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #0

2017-01-12 21:00:55,479 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: registerApplicationMaster took 142ms

2017-01-12 21:00:55,485 INFO type (ApplicationMaster.java:start) - ApplicationMaster registered

2017-01-12 21:00:55,486 DEBUG type (ApplicationMaster.java:masterExists) - Checking for master at: http://ip-10-253-194-85.ec2.internal:19999/api/v1/master/version

2017-01-12 21:00:55,497 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #1

2017-01-12 21:00:55,499 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #1

2017-01-12 21:00:55,499 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 3ms

2017-01-12 21:00:55,512 DEBUG type (ApplicationMaster.java:masterExists) - Response code from master was: 200

2017-01-12 21:00:55,518 INFO type (ApplicationMaster.java:requestAndLaunchContainers) - Found master already running on ip-10-253-194-85.ec2.internal

2017-01-12 21:00:55,522 DEBUG type (ContainerAllocator.java:allocateContainers) - Attempt 0 of 20 to allocate containers

2017-01-12 21:00:55,522 DEBUG type (ContainerAllocator.java:allocateContainers) - Requesting 8 containers

2017-01-12 21:00:55,522 INFO type (ContainerAllocator.java:requestContainers) - Requesting 8 worker containers

2017-01-12 21:00:55,535 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:00:55,535 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-85.ec2.internal/10.253.194.85:8032

2017-01-12 21:00:55,536 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:00:55,536 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:00:55,538 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

auths {

method: "SIMPLE"

mechanism: ""

}

2017-01-12 21:00:55,538 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ApplicationClientProtocolPB info:org.apache.hadoop.yarn.security.client.ClientRMSecurityInfo$2@1efe439d

2017-01-12 21:00:55,539 DEBUG RMDelegationTokenSelector (RMDelegationTokenSelector.java:selectToken) - Looking for a token with service 10.253.194.85:8032

2017-01-12 21:00:55,540 DEBUG RMDelegationTokenSelector (RMDelegationTokenSelector.java:selectToken) - Token kind is YARN_AM_RM_TOKEN and the token's service name is 10.253.194.85:8030

2017-01-12 21:00:55,541 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use SIMPLE authentication for protocol ApplicationClientProtocolPB

2017-01-12 21:00:55,542 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

auths {

method: "SIMPLE"

mechanism: ""

}

2017-01-12 21:00:55,543 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn: starting, having connections 2

2017-01-12 21:00:55,543 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn sending #2

2017-01-12 21:00:55,545 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn got value #2

2017-01-12 21:00:55,545 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 10ms

2017-01-12 21:00:55,560 INFO type (ContainerAllocator.java:requestContainers) - Making 8 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-102.ec2.internal, ip-10-253-194-72.ec2.internal, ip-10-253-194-98.ec2.internal, ip-10-253-194-41.ec2.internal, ip-10-253-194-218.ec2.internal, ip-10-253-194-224.ec2.internal, ip-10-253-194-16.ec2.internal, ip-10-253-194-122.ec2.internal]

2017-01-12 21:00:55,561 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,563 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,563 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,564 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,565 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,566 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,567 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,568 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,568 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - Added priority=101

2017-01-12 21:00:55,573 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=1 #asks=1

2017-01-12 21:00:55,574 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-72.ec2.internal numContainers=1 #asks=5

2017-01-12 21:00:55,574 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=1 #asks=9

2017-01-12 21:00:55,574 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=1 #asks=10

2017-01-12 21:00:55,574 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,574 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,574 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,575 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,575 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,575 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,575 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,575 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,575 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=2 #asks=10

2017-01-12 21:00:55,576 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-16.ec2.internal numContainers=2 #asks=10

2017-01-12 21:00:55,576 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=2 #asks=10

2017-01-12 21:00:55,576 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=2 #asks=10

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,577 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,577 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=3 #asks=10

2017-01-12 21:00:55,578 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-218.ec2.internal numContainers=3 #asks=10

2017-01-12 21:00:55,578 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=3 #asks=10

2017-01-12 21:00:55,578 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=3 #asks=10

2017-01-12 21:00:55,578 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,578 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,578 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,579 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,579 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,579 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,579 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,579 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,579 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=4 #asks=10

2017-01-12 21:00:55,580 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=4 #asks=10

2017-01-12 21:00:55,580 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=4 #asks=10

2017-01-12 21:00:55,580 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=4 #asks=10

2017-01-12 21:00:55,580 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,580 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,580 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,580 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,580 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,581 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,581 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,581 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,581 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=5 #asks=10

2017-01-12 21:00:55,582 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-102.ec2.internal numContainers=5 #asks=10

2017-01-12 21:00:55,582 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=5 #asks=10

2017-01-12 21:00:55,582 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=5 #asks=10

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,582 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,583 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=6 #asks=10

2017-01-12 21:00:55,583 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=6 #asks=10

2017-01-12 21:00:55,583 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=6 #asks=10

2017-01-12 21:00:55,583 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,584 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,584 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=7 #asks=10

2017-01-12 21:00:55,585 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-72.ec2.internal numContainers=7 #asks=10

2017-01-12 21:00:55,585 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=7 #asks=10

2017-01-12 21:00:55,585 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=7 #asks=10

2017-01-12 21:00:55,585 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:55,585 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-72.ec2.internal to /default-rack

2017-01-12 21:00:55,585 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:55,585 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:55,586 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:55,586 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-224.ec2.internal to /default-rack

2017-01-12 21:00:55,586 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:55,586 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-122.ec2.internal to /default-rack

2017-01-12 21:00:55,586 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-224.ec2.internal numContainers=8 #asks=10

2017-01-12 21:00:55,587 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-41.ec2.internal numContainers=8 #asks=10

2017-01-12 21:00:55,587 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=8 #asks=10

2017-01-12 21:00:55,587 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=8 #asks=10

2017-01-12 21:00:56,019 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #3

2017-01-12 21:00:56,021 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #3

2017-01-12 21:00:56,021 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 2ms

2017-01-12 21:00:56,522 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #4

2017-01-12 21:00:56,527 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #4

2017-01-12 21:00:56,527 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 6ms

2017-01-12 21:00:56,531 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-72.ec2.internal:8041

2017-01-12 21:00:56,531 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-224.ec2.internal:8041

2017-01-12 21:00:56,532 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-122.ec2.internal:8041

2017-01-12 21:00:56,535 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-72.ec2.internal

2017-01-12 21:00:56,540 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-72.ec2.internal

2017-01-12 21:00:56,540 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-224.ec2.internal

2017-01-12 21:00:56,540 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:56,540 DEBUG type (ContainerAllocator.java:allocateContainers) - Attempt 1 of 20 to allocate containers

2017-01-12 21:00:56,541 DEBUG type (ContainerAllocator.java:allocateContainers) - Requesting 5 containers

2017-01-12 21:00:56,541 INFO type (ContainerAllocator.java:requestContainers) - Requesting 5 worker containers

2017-01-12 21:00:56,541 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn sending #5

2017-01-12 21:00:56,542 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn got value #5

2017-01-12 21:00:56,542 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 1ms

2017-01-12 21:00:56,543 INFO type (ContainerAllocator.java:requestContainers) - Making 5 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-102.ec2.internal, ip-10-253-194-98.ec2.internal, ip-10-253-194-41.ec2.internal, ip-10-253-194-218.ec2.internal, ip-10-253-194-16.ec2.internal]

2017-01-12 21:00:56,543 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:56,543 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:56,543 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:56,544 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:56,544 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:56,544 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-16.ec2.internal numContainers=9 #asks=1

2017-01-12 21:00:56,545 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=9 #asks=6

2017-01-12 21:00:56,545 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=9 #asks=7

2017-01-12 21:00:56,545 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:56,545 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:56,545 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:56,545 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:56,545 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:56,546 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-16.ec2.internal numContainers=10 #asks=7

2017-01-12 21:00:56,546 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=10 #asks=7

2017-01-12 21:00:56,546 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=10 #asks=7

2017-01-12 21:00:56,547 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:56,547 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:56,547 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:56,547 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:56,547 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:56,547 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-16.ec2.internal numContainers=11 #asks=7

2017-01-12 21:00:56,548 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=11 #asks=7

2017-01-12 21:00:56,548 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=11 #asks=7

2017-01-12 21:00:56,548 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=11 #asks=7

2017-01-12 21:00:56,548 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:56,548 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:56,549 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:56,549 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:56,549 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:56,549 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-16.ec2.internal numContainers=12 #asks=7

2017-01-12 21:00:56,550 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-102.ec2.internal numContainers=12 #asks=7

2017-01-12 21:00:56,550 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=12 #asks=7

2017-01-12 21:00:56,550 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=12 #asks=7

2017-01-12 21:00:56,550 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:56,550 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:56,550 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-41.ec2.internal to /default-rack

2017-01-12 21:00:56,550 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-218.ec2.internal to /default-rack

2017-01-12 21:00:56,551 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-16.ec2.internal to /default-rack

2017-01-12 21:00:56,551 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-16.ec2.internal numContainers=13 #asks=7

2017-01-12 21:00:56,551 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=13 #asks=7

2017-01-12 21:00:56,552 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=13 #asks=7

2017-01-12 21:00:57,034 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #6

2017-01-12 21:00:57,039 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #6

2017-01-12 21:00:57,039 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 5ms

2017-01-12 21:00:57,043 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000003

2017-01-12 21:00:57,043 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000004

2017-01-12 21:00:57,043 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000007

2017-01-12 21:00:57,043 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000008

2017-01-12 21:00:57,044 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000011

2017-01-12 21:00:57,543 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #7

2017-01-12 21:00:57,551 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #7

2017-01-12 21:00:57,551 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 8ms

2017-01-12 21:00:57,552 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-41.ec2.internal:8041

2017-01-12 21:00:57,552 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-218.ec2.internal:8041

2017-01-12 21:00:57,552 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-16.ec2.internal:8041

2017-01-12 21:00:57,552 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-72.ec2.internal

2017-01-12 21:00:57,553 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-72.ec2.internal

2017-01-12 21:00:57,553 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-224.ec2.internal

2017-01-12 21:00:57,553 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:57,553 DEBUG type (ContainerAllocator.java:allocateContainers) - Attempt 2 of 20 to allocate containers

2017-01-12 21:00:57,553 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:57,553 DEBUG type (ContainerAllocator.java:allocateContainers) - Requesting 5 containers

2017-01-12 21:00:57,553 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-41.ec2.internal

2017-01-12 21:00:57,553 INFO type (ContainerAllocator.java:requestContainers) - Requesting 5 worker containers

2017-01-12 21:00:57,554 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-41.ec2.internal

2017-01-12 21:00:57,554 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-218.ec2.internal

2017-01-12 21:00:57,554 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn sending #8

2017-01-12 21:00:57,555 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn got value #8

2017-01-12 21:00:57,555 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 1ms

2017-01-12 21:00:57,556 INFO type (ContainerAllocator.java:requestContainers) - Making 5 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-102.ec2.internal, ip-10-253-194-98.ec2.internal]

2017-01-12 21:00:57,556 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,556 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,556 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=14 #asks=1

2017-01-12 21:00:57,556 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=14 #asks=3

2017-01-12 21:00:57,557 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=14 #asks=4

2017-01-12 21:00:57,557 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,557 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,557 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=15 #asks=4

2017-01-12 21:00:57,557 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=15 #asks=4

2017-01-12 21:00:57,557 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=15 #asks=4

2017-01-12 21:00:57,557 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,557 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,558 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=16 #asks=4

2017-01-12 21:00:57,558 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=16 #asks=4

2017-01-12 21:00:57,558 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=16 #asks=4

2017-01-12 21:00:57,558 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,558 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,559 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=17 #asks=4

2017-01-12 21:00:57,559 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=17 #asks=4

2017-01-12 21:00:57,559 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,559 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,559 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=18 #asks=4

2017-01-12 21:00:57,560 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-102.ec2.internal numContainers=18 #asks=4

2017-01-12 21:00:57,560 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=18 #asks=4

2017-01-12 21:00:57,560 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=18 #asks=4

2017-01-12 21:00:57,560 DEBUG type (ContainerAllocator.java:allocateContainers) - Attempt 3 of 20 to allocate containers

2017-01-12 21:00:57,560 DEBUG type (ContainerAllocator.java:allocateContainers) - Requesting 2 containers

2017-01-12 21:00:57,560 INFO type (ContainerAllocator.java:requestContainers) - Requesting 2 worker containers

2017-01-12 21:00:57,560 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn sending #9

2017-01-12 21:00:57,562 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn got value #9

2017-01-12 21:00:57,562 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 2ms

2017-01-12 21:00:57,562 INFO type (ContainerAllocator.java:requestContainers) - Making 2 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-102.ec2.internal, ip-10-253-194-98.ec2.internal]

2017-01-12 21:00:57,562 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,563 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,563 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=19 #asks=4

2017-01-12 21:00:57,563 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=19 #asks=4

2017-01-12 21:00:57,563 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=19 #asks=4

2017-01-12 21:00:57,563 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-102.ec2.internal to /default-rack

2017-01-12 21:00:57,563 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:57,564 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-102.ec2.internal numContainers=20 #asks=4

2017-01-12 21:00:57,564 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=20 #asks=4

2017-01-12 21:00:57,564 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=20 #asks=4

2017-01-12 21:00:58,053 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #10

2017-01-12 21:00:58,067 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #10

2017-01-12 21:00:58,067 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 14ms

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000012

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000013

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000022

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000023

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000026

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000027

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000015

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000016

2017-01-12 21:00:58,068 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000018

2017-01-12 21:00:58,069 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000019

2017-01-12 21:00:58,568 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #11

2017-01-12 21:00:58,584 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #11

2017-01-12 21:00:58,584 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 16ms

2017-01-12 21:00:58,585 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-102.ec2.internal:8041

2017-01-12 21:00:58,585 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-72.ec2.internal

2017-01-12 21:00:58,585 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-224.ec2.internal

2017-01-12 21:00:58,585 DEBUG type (ContainerAllocator.java:allocateContainers) - Attempt 4 of 20 to allocate containers

2017-01-12 21:00:58,585 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-224.ec2.internal

2017-01-12 21:00:58,585 DEBUG type (ContainerAllocator.java:allocateContainers) - Requesting 2 containers

2017-01-12 21:00:58,586 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:58,586 INFO type (ContainerAllocator.java:requestContainers) - Requesting 2 worker containers

2017-01-12 21:00:58,586 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:58,586 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-41.ec2.internal

2017-01-12 21:00:58,586 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn sending #12

2017-01-12 21:00:58,586 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-218.ec2.internal

2017-01-12 21:00:58,586 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-16.ec2.internal

2017-01-12 21:00:58,587 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-16.ec2.internal

2017-01-12 21:00:58,587 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-102.ec2.internal

2017-01-12 21:00:58,587 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn got value #12

2017-01-12 21:00:58,588 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 2ms

2017-01-12 21:00:58,588 INFO type (ContainerAllocator.java:requestContainers) - Making 2 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-98.ec2.internal]

2017-01-12 21:00:58,588 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:58,588 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=21 #asks=1

2017-01-12 21:00:58,588 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=21 #asks=2

2017-01-12 21:00:58,589 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=21 #asks=3

2017-01-12 21:00:58,589 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:58,589 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=22 #asks=3

2017-01-12 21:00:58,589 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=22 #asks=3

2017-01-12 21:00:58,589 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=22 #asks=3

2017-01-12 21:00:58,589 DEBUG type (ContainerAllocator.java:allocateContainers) - Attempt 5 of 20 to allocate containers

2017-01-12 21:00:58,589 DEBUG type (ContainerAllocator.java:allocateContainers) - Requesting 1 containers

2017-01-12 21:00:58,589 INFO type (ContainerAllocator.java:requestContainers) - Requesting 1 worker containers

2017-01-12 21:00:58,589 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn sending #13

2017-01-12 21:00:58,590 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8032 from yarn got value #13

2017-01-12 21:00:58,591 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getClusterNodes took 2ms

2017-01-12 21:00:58,591 INFO type (ContainerAllocator.java:requestContainers) - Making 1 resource request(s) for Alluxio workers with cpu 1 memory 7168MB on hosts [ip-10-253-194-98.ec2.internal]

2017-01-12 21:00:58,591 INFO RackResolver (RackResolver.java:coreResolve) - Resolved ip-10-253-194-98.ec2.internal to /default-rack

2017-01-12 21:00:58,591 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=ip-10-253-194-98.ec2.internal numContainers=23 #asks=3

2017-01-12 21:00:58,591 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=/default-rack numContainers=23 #asks=3

2017-01-12 21:00:58,591 DEBUG AMRMClientImpl (AMRMClientImpl.java:addResourceRequest) - addResourceRequest: applicationId= priority=101 resourceName=* numContainers=23 #asks=3

2017-01-12 21:00:59,086 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #14

2017-01-12 21:00:59,098 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #14

2017-01-12 21:00:59,098 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 13ms

2017-01-12 21:00:59,099 INFO AMRMClientImpl (AMRMClientImpl.java:populateNMTokens) - Received new token for : ip-10-253-194-98.ec2.internal:8041

2017-01-12 21:00:59,099 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000049

2017-01-12 21:00:59,099 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000050

2017-01-12 21:00:59,099 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000030

2017-01-12 21:00:59,099 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000031

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000039

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000040

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000042

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000043

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000033

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000034

2017-01-12 21:00:59,100 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000045

2017-01-12 21:00:59,101 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000046

2017-01-12 21:00:59,101 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000036

2017-01-12 21:00:59,101 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000037

2017-01-12 21:00:59,101 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-98.ec2.internal

2017-01-12 21:00:59,156 DEBUG type (Configuration.java:lookupRecursively) - Replacing ${alluxio.home} with /mnt/yarn/usercache/hadoop/appcache/application_1484252891624_0004/container_1484252891624_0004_01_000001

2017-01-12 21:00:59,156 DEBUG type (Configuration.java:lookupRecursively) - Replacing ${alluxio.conf.dir} with /mnt/yarn/usercache/hadoop/appcache/application_1484252891624_0004/container_1484252891624_0004_01_000001/conf

2017-01-12 21:00:59,162 INFO type (MetricsSystem.java:startSinksFromConfig) - Starting sinks with config: {}.

2017-01-12 21:00:59,387 DEBUG BlockReaderLocal (DFSClient.java:<init>) - dfs.client.use.legacy.blockreader.local = false

2017-01-12 21:00:59,387 DEBUG BlockReaderLocal (DFSClient.java:<init>) - dfs.client.read.shortcircuit = false

2017-01-12 21:00:59,387 DEBUG BlockReaderLocal (DFSClient.java:<init>) - dfs.client.domain.socket.data.traffic = false

2017-01-12 21:00:59,387 DEBUG BlockReaderLocal (DFSClient.java:<init>) - dfs.domain.socket.path =

2017-01-12 21:00:59,410 DEBUG RetryUtils (RetryUtils.java:getDefaultRetryPolicy) - multipleLinearRandomRetry = null

2017-01-12 21:00:59,415 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:00:59,599 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #15

2017-01-12 21:00:59,603 DEBUG DomainSocketWatcher (DomainSocketWatcher.java:run) - org.apache.hadoop.net.unix.DomainSocketWatcher$2@7cc4a8fa: starting with interruptCheckPeriodMs = 60000

2017-01-12 21:00:59,607 DEBUG PerformanceAdvisory (DomainSocketFactory.java:<init>) - Both short-circuit local reads and UNIX domain socket are disabled.

2017-01-12 21:00:59,611 DEBUG DataTransferSaslUtil (DataTransferSaslUtil.java:getSaslPropertiesResolver) - DataTransferProtocol not using SaslPropertiesResolver, no QOP found in configuration for dfs.data.transfer.protection

2017-01-12 21:00:59,613 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #15

2017-01-12 21:00:59,614 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 15ms

2017-01-12 21:00:59,615 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000053

2017-01-12 21:00:59,615 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000054

2017-01-12 21:00:59,615 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:59,616 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-122.ec2.internal

2017-01-12 21:00:59,616 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-41.ec2.internal

2017-01-12 21:00:59,616 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-218.ec2.internal

2017-01-12 21:00:59,616 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:00:59,616 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-218.ec2.internal

2017-01-12 21:00:59,616 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-85.ec2.internal/10.253.194.85:8020

2017-01-12 21:00:59,616 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-16.ec2.internal

2017-01-12 21:00:59,617 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-16.ec2.internal

2017-01-12 21:00:59,617 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-102.ec2.internal

2017-01-12 21:00:59,617 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:yarn (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:00:59,617 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:00:59,619 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

auths {

method: "SIMPLE"

mechanism: ""

}

2017-01-12 21:00:59,619 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB info:@org.apache.hadoop.security.token.TokenInfo(value=class org.apache.hadoop.hdfs.security.token.delegation.DelegationTokenSelector)

2017-01-12 21:00:59,619 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use SIMPLE authentication for protocol ClientNamenodeProtocolPB

2017-01-12 21:00:59,619 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

auths {

method: "SIMPLE"

mechanism: ""

}

2017-01-12 21:00:59,621 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn: starting, having connections 3

2017-01-12 21:00:59,622 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #16

2017-01-12 21:00:59,623 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #16

2017-01-12 21:00:59,623 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 7ms

2017-01-12 21:00:59,708 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #17

2017-01-12 21:00:59,710 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #17

2017-01-12 21:00:59,710 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 2ms

2017-01-12 21:00:59,712 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000002 for Alluxio worker on ip-10-253-194-72.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:00:59,714 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-72.ec2.internal:8041

2017-01-12 21:00:59,753 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.72:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-72.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:00:59,795 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:00:59,795 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:00:59,798 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:00:59,817 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:00:59,817 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-72.ec2.internal/10.253.194.72:8041

2017-01-12 21:00:59,818 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:00:59,819 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:00:59,820 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:00:59,821 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@3e1162e7

2017-01-12 21:00:59,821 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.72:8041. Current token is Kind: NMToken, Service: 10.253.194.72:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-72.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:00:59,822 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:00:59,822 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:00:59,822 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEigKI2lwLTEwLTI1My0xOTQtNzIubm9ucHJkLmF3cy5jc3AubmV0EOk+GgZoYWRvb3Ag/Pqh4QQ=

2017-01-12 21:00:59,822 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:00:59,822 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:00:59,823 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:00:59,826 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:00:59,826 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:00:59,827 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-72.ec2.internal/10.253.194.72:8041 from appattempt_1484252891624_0004_000001 sending #18

2017-01-12 21:00:59,827 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-72.ec2.internal/10.253.194.72:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:00:59,831 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-72.ec2.internal/10.253.194.72:8041 from appattempt_1484252891624_0004_000001 got value #18

2017-01-12 21:00:59,831 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-72.ec2.internal/10.253.194.72:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:00:59,832 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-72.ec2.internal/10.253.194.72:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:00:59,832 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 15ms

2017-01-12 21:00:59,875 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #19

2017-01-12 21:00:59,876 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #19

2017-01-12 21:00:59,888 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 13ms

2017-01-12 21:00:59,927 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #20

2017-01-12 21:00:59,928 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #20

2017-01-12 21:00:59,929 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 3ms

2017-01-12 21:00:59,930 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000006 for Alluxio worker on ip-10-253-194-224.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:00:59,931 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-224.ec2.internal:8041

2017-01-12 21:00:59,937 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.224:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-224.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:00:59,938 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:00:59,938 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:00:59,938 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:00:59,939 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:00:59,939 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-224.ec2.internal/10.253.194.224:8041

2017-01-12 21:00:59,940 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:00:59,941 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:00:59,946 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:00:59,947 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@584f5497

2017-01-12 21:00:59,948 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.224:8041. Current token is Kind: NMToken, Service: 10.253.194.224:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-224.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:00:59,948 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:00:59,949 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:00:59,949 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEikKJGlwLTEwLTI1My0xOTQtMjI0Lm5vbnByZC5hd3MuY3NwLm5ldBDpPhoGaGFkb29wIPz6oeEE

2017-01-12 21:00:59,949 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:00:59,949 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:00:59,952 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:00:59,954 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:00:59,955 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:00:59,955 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-224.ec2.internal/10.253.194.224:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:00:59,956 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-224.ec2.internal/10.253.194.224:8041 from appattempt_1484252891624_0004_000001 sending #21

2017-01-12 21:00:59,960 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-224.ec2.internal/10.253.194.224:8041 from appattempt_1484252891624_0004_000001 got value #21

2017-01-12 21:00:59,960 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-224.ec2.internal/10.253.194.224:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:00:59,960 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-224.ec2.internal/10.253.194.224:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:00:59,960 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 21ms

2017-01-12 21:00:59,988 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #22

2017-01-12 21:00:59,988 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #22

2017-01-12 21:00:59,989 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 2ms

2017-01-12 21:01:00,029 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #23

2017-01-12 21:01:00,030 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #23

2017-01-12 21:01:00,030 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 1ms

2017-01-12 21:01:00,031 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000010 for Alluxio worker on ip-10-253-194-122.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:01:00,031 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-122.ec2.internal:8041

2017-01-12 21:01:00,032 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.122:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-122.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,033 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:01:00,033 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:01:00,034 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:01:00,035 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:01:00,035 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-122.ec2.internal/10.253.194.122:8041

2017-01-12 21:01:00,036 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:01:00,037 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:01:00,038 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:01:00,038 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@5aa6202e

2017-01-12 21:01:00,039 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.122:8041. Current token is Kind: NMToken, Service: 10.253.194.122:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-122.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,039 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:01:00,040 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:01:00,040 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEikKJGlwLTEwLTI1My0xOTQtMTIyLm5vbnByZC5hd3MuY3NwLm5ldBDpPhoGaGFkb29wIPz6oeEE

2017-01-12 21:01:00,040 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:01:00,040 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:01:00,041 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:01:00,045 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:01:00,045 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:01:00,052 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-122.ec2.internal/10.253.194.122:8041 from appattempt_1484252891624_0004_000001 sending #24

2017-01-12 21:01:00,052 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-122.ec2.internal/10.253.194.122:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:01:00,059 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-122.ec2.internal/10.253.194.122:8041 from appattempt_1484252891624_0004_000001 got value #24

2017-01-12 21:01:00,060 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 25ms

2017-01-12 21:01:00,073 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-122.ec2.internal/10.253.194.122:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:01:00,073 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-122.ec2.internal/10.253.194.122:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:01:00,089 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #25

2017-01-12 21:01:00,090 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #25

2017-01-12 21:01:00,091 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 3ms

2017-01-12 21:01:00,115 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #26

2017-01-12 21:01:00,116 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #26

2017-01-12 21:01:00,116 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #27

2017-01-12 21:01:00,116 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 3ms

2017-01-12 21:01:00,117 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000021 for Alluxio worker on ip-10-253-194-41.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:01:00,117 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-41.ec2.internal:8041

2017-01-12 21:01:00,119 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.41:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-41.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,120 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:01:00,120 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:01:00,122 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:01:00,123 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:01:00,124 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-41.ec2.internal/10.253.194.41:8041

2017-01-12 21:01:00,125 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:01:00,126 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:01:00,127 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:01:00,127 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@3163987e

2017-01-12 21:01:00,129 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.41:8041. Current token is Kind: NMToken, Service: 10.253.194.41:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-41.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,131 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:01:00,131 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:01:00,131 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEigKI2lwLTEwLTI1My0xOTQtNDEubm9ucHJkLmF3cy5jc3AubmV0EOk+GgZoYWRvb3Ag/Pqh4QQ=

2017-01-12 21:01:00,132 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:01:00,132 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:01:00,137 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:01:00,140 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:01:00,140 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:01:00,148 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-41.ec2.internal/10.253.194.41:8041 from appattempt_1484252891624_0004_000001 sending #28

2017-01-12 21:01:00,149 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-41.ec2.internal/10.253.194.41:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:01:00,152 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-41.ec2.internal/10.253.194.41:8041 from appattempt_1484252891624_0004_000001 got value #28

2017-01-12 21:01:00,152 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 29ms

2017-01-12 21:01:00,156 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #27

2017-01-12 21:01:00,156 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 41ms

2017-01-12 21:01:00,165 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000068

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000069

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000060

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000061

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000063

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000064

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000047

2017-01-12 21:01:00,166 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000066

2017-01-12 21:01:00,167 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000038

2017-01-12 21:01:00,167 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000059

2017-01-12 21:01:00,167 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-98.ec2.internal

2017-01-12 21:01:00,167 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-72.ec2.internal

2017-01-12 21:01:00,167 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-224.ec2.internal

2017-01-12 21:01:00,185 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-41.ec2.internal/10.253.194.41:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:01:00,185 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-41.ec2.internal/10.253.194.41:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:01:00,192 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #29

2017-01-12 21:01:00,193 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #29

2017-01-12 21:01:00,193 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 3ms

2017-01-12 21:01:00,234 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #30

2017-01-12 21:01:00,235 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #30

2017-01-12 21:01:00,235 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 1ms

2017-01-12 21:01:00,236 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000025 for Alluxio worker on ip-10-253-194-218.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:01:00,236 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-218.ec2.internal:8041

2017-01-12 21:01:00,237 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.218:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-218.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,239 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:01:00,239 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:01:00,240 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:01:00,240 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:01:00,241 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-218.ec2.internal/10.253.194.218:8041

2017-01-12 21:01:00,241 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:01:00,242 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:01:00,245 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:01:00,245 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@22df874e

2017-01-12 21:01:00,246 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.218:8041. Current token is Kind: NMToken, Service: 10.253.194.218:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-218.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,246 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:01:00,246 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:01:00,246 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEikKJGlwLTEwLTI1My0xOTQtMjE4Lm5vbnByZC5hd3MuY3NwLm5ldBDpPhoGaGFkb29wIPz6oeEE

2017-01-12 21:01:00,247 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:01:00,247 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:01:00,247 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:01:00,251 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:01:00,251 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:01:00,258 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-218.ec2.internal/10.253.194.218:8041 from appattempt_1484252891624_0004_000001 sending #31

2017-01-12 21:01:00,258 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-218.ec2.internal/10.253.194.218:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:01:00,264 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-218.ec2.internal/10.253.194.218:8041 from appattempt_1484252891624_0004_000001 got value #31

2017-01-12 21:01:00,264 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 24ms

2017-01-12 21:01:00,274 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-218.ec2.internal/10.253.194.218:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:01:00,274 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-218.ec2.internal/10.253.194.218:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:01:00,286 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #32

2017-01-12 21:01:00,287 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #32

2017-01-12 21:01:00,287 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 1ms

2017-01-12 21:01:00,310 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #33

2017-01-12 21:01:00,311 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #33

2017-01-12 21:01:00,311 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 1ms

2017-01-12 21:01:00,312 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000029 for Alluxio worker on ip-10-253-194-16.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:01:00,312 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-16.ec2.internal:8041

2017-01-12 21:01:00,313 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.16:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-16.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,314 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:01:00,314 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:01:00,316 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:01:00,317 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:01:00,317 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-16.ec2.internal/10.253.194.16:8041

2017-01-12 21:01:00,318 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:01:00,319 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:01:00,320 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:01:00,321 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@5339bbad

2017-01-12 21:01:00,325 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.16:8041. Current token is Kind: NMToken, Service: 10.253.194.16:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-16.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,326 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:01:00,328 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:01:00,328 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEigKI2lwLTEwLTI1My0xOTQtMTYubm9ucHJkLmF3cy5jc3AubmV0EOk+GgZoYWRvb3Ag/Pqh4QQ=

2017-01-12 21:01:00,328 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:01:00,328 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:01:00,333 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:01:00,336 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:01:00,337 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:01:00,341 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-16.ec2.internal/10.253.194.16:8041 from appattempt_1484252891624_0004_000001 sending #34

2017-01-12 21:01:00,342 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-16.ec2.internal/10.253.194.16:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:01:00,346 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-16.ec2.internal/10.253.194.16:8041 from appattempt_1484252891624_0004_000001 got value #34

2017-01-12 21:01:00,346 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 29ms

2017-01-12 21:01:00,346 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-16.ec2.internal/10.253.194.16:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:01:00,347 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-16.ec2.internal/10.253.194.16:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:01:00,377 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #35

2017-01-12 21:01:00,378 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #35

2017-01-12 21:01:00,378 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 2ms

2017-01-12 21:01:00,410 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #36

2017-01-12 21:01:00,411 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #36

2017-01-12 21:01:00,411 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 2ms

2017-01-12 21:01:00,412 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000048 for Alluxio worker on ip-10-253-194-102.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:01:00,412 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-102.ec2.internal:8041

2017-01-12 21:01:00,414 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.102:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-102.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,415 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:01:00,415 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:01:00,415 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:01:00,416 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:01:00,416 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-102.ec2.internal/10.253.194.102:8041

2017-01-12 21:01:00,417 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:01:00,417 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:01:00,418 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:01:00,418 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@4fe01805

2017-01-12 21:01:00,420 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.102:8041. Current token is Kind: NMToken, Service: 10.253.194.102:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-102.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,420 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:01:00,420 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:01:00,420 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEikKJGlwLTEwLTI1My0xOTQtMTAyLm5vbnByZC5hd3MuY3NwLm5ldBDpPhoGaGFkb29wIPz6oeEE

2017-01-12 21:01:00,421 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:01:00,421 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:01:00,421 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:01:00,425 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:01:00,426 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:01:00,426 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-102.ec2.internal/10.253.194.102:8041 from appattempt_1484252891624_0004_000001 sending #37

2017-01-12 21:01:00,429 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-102.ec2.internal/10.253.194.102:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:01:00,432 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-102.ec2.internal/10.253.194.102:8041 from appattempt_1484252891624_0004_000001 got value #37

2017-01-12 21:01:00,433 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 17ms

2017-01-12 21:01:00,433 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-102.ec2.internal/10.253.194.102:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:01:00,433 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-102.ec2.internal/10.253.194.102:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:01:00,462 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #38

2017-01-12 21:01:00,465 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #38

2017-01-12 21:01:00,466 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 5ms

2017-01-12 21:01:00,488 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn sending #39

2017-01-12 21:01:00,489 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8020 from yarn got value #39

2017-01-12 21:01:00,489 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: getFileInfo took 3ms

2017-01-12 21:01:00,490 INFO type (ApplicationMaster.java:launchWorkerContainer) - Launching container container_1484252891624_0004_01_000052 for Alluxio worker on ip-10-253-194-98.ec2.internal:8042 with worker command: ./alluxio-yarn-setup.sh alluxio-worker 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr

2017-01-12 21:01:00,490 INFO ContainerManagementProtocolProxy (ContainerManagementProtocolProxy.java:newProxy) - Opening proxy : ip-10-253-194-98.ec2.internal:8041

2017-01-12 21:01:00,491 DEBUG SecurityUtil (SecurityUtil.java:setTokenService) - Acquired token Kind: NMToken, Service: 10.253.194.98:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-98.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,492 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.yarn.client.ServerProxy.createRetriableProxy(ServerProxy.java:93)

2017-01-12 21:01:00,492 DEBUG HadoopYarnProtoRPC (HadoopYarnProtoRPC.java:getProxy) - Creating a HadoopYarnProtoRpc proxy for protocol interface org.apache.hadoop.yarn.api.ContainerManagementProtocol

2017-01-12 21:01:00,493 DEBUG Client (ClientCache.java:getClient) - getting client out of cache: org.apache.hadoop.ipc.Client@6babf3bf

2017-01-12 21:01:00,493 DEBUG Client (Client.java:<init>) - The ping interval is 60000 ms.

2017-01-12 21:01:00,493 DEBUG Client (Client.java:setupIOstreams) - Connecting to ip-10-253-194-98.ec2.internal/10.253.194.98:8041

2017-01-12 21:01:00,494 DEBUG UserGroupInformation (UserGroupInformation.java:logPrivilegedAction) - PrivilegedAction as:appattempt_1484252891624_0004_000001 (auth:SIMPLE) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:725)

2017-01-12 21:01:00,496 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: NEGOTIATE

2017-01-12 21:01:00,497 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: NEGOTIATE

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

challenge: "<REMOVED>"

}

2017-01-12 21:01:00,497 DEBUG SaslRpcClient (SaslRpcClient.java:getServerToken) - Get token info proto:interface org.apache.hadoop.yarn.api.ContainerManagementProtocolPB info:org.apache.hadoop.yarn.security.ContainerManagerSecurityInfo$1@72be135f

2017-01-12 21:01:00,506 INFO NMTokenSelector (NMTokenSelector.java:selectToken) - Looking for service: 10.253.194.98:8041. Current token is Kind: NMToken, Service: 10.253.194.98:8041, Ident: (appAttemptId { application_id { id: 4 cluster_timestamp: 1484252891624 } attemptId: 1 } nodeId { host: "ip-10-253-194-98.ec2.internal" port: 8041 } appSubmitter: "hadoop" keyId: 1277721980)

2017-01-12 21:01:00,507 DEBUG SaslRpcClient (SaslRpcClient.java:createSaslClient) - Creating SASL DIGEST-MD5(TOKEN) client to authenticate to service at default

2017-01-12 21:01:00,508 DEBUG SaslRpcClient (SaslRpcClient.java:selectSaslClient) - Use TOKEN authentication for protocol ContainerManagementProtocolPB

2017-01-12 21:01:00,508 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting username: Cg0KCQgEEOiT96KZKxABEigKI2lwLTEwLTI1My0xOTQtOTgubm9ucHJkLmF3cy5jc3AubmV0EOk+GgZoYWRvb3Ag/Pqh4QQ=

2017-01-12 21:01:00,508 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting userPassword

2017-01-12 21:01:00,508 DEBUG SaslRpcClient (SaslRpcClient.java:handle) - SASL client callback: setting realm: default

2017-01-12 21:01:00,510 DEBUG SaslRpcClient (SaslRpcClient.java:sendSaslMessage) - Sending sasl message state: INITIATE

token: "<REMOVED>"

auths {

method: "TOKEN"

mechanism: "DIGEST-MD5"

protocol: ""

serverId: "default"

}

2017-01-12 21:01:00,513 DEBUG SaslRpcClient (SaslRpcClient.java:saslConnect) - Received SASL message state: SUCCESS

token: "<REMOVED>"

2017-01-12 21:01:00,514 DEBUG Client (Client.java:setupIOstreams) - Negotiated QOP is :auth

2017-01-12 21:01:00,517 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-98.ec2.internal/10.253.194.98:8041 from appattempt_1484252891624_0004_000001 sending #40

2017-01-12 21:01:00,518 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-98.ec2.internal/10.253.194.98:8041 from appattempt_1484252891624_0004_000001: starting, having connections 4

2017-01-12 21:01:00,521 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-98.ec2.internal/10.253.194.98:8041 from appattempt_1484252891624_0004_000001 got value #40

2017-01-12 21:01:00,521 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: startContainers took 28ms

2017-01-12 21:01:00,522 INFO type (ApplicationMaster.java:requestAndLaunchContainers) - Master and workers are launched

2017-01-12 21:01:00,522 DEBUG Client (Client.java:close) - IPC Client (702846463) connection to ip-10-253-194-98.ec2.internal/10.253.194.98:8041 from appattempt_1484252891624_0004_000001: closed

2017-01-12 21:01:00,522 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-98.ec2.internal/10.253.194.98:8041 from appattempt_1484252891624_0004_000001: stopped, remaining connections 3

2017-01-12 21:01:00,657 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #41

2017-01-12 21:01:00,667 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #41

2017-01-12 21:01:00,667 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 10ms

2017-01-12 21:01:00,668 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000071

2017-01-12 21:01:00,668 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-41.ec2.internal

2017-01-12 21:01:00,668 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-218.ec2.internal

2017-01-12 21:01:00,668 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-16.ec2.internal

2017-01-12 21:01:00,668 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-102.ec2.internal

2017-01-12 21:01:01,168 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #42

2017-01-12 21:01:01,182 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #42

2017-01-12 21:01:01,182 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 14ms

2017-01-12 21:01:01,184 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000082

2017-01-12 21:01:01,185 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000083

2017-01-12 21:01:01,186 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000074

2017-01-12 21:01:01,186 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000072

2017-01-12 21:01:01,186 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000062

2017-01-12 21:01:01,186 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000076

2017-01-12 21:01:01,186 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000065

2017-01-12 21:01:01,186 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000078

2017-01-12 21:01:01,187 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000075

2017-01-12 21:01:01,187 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000067

2017-01-12 21:01:01,187 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000080

2017-01-12 21:01:01,187 INFO type (ContainerAllocator.java:allocateContainer) - Releasing assigned container on host ip-10-253-194-98.ec2.internal

2017-01-12 21:01:01,683 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #43

2017-01-12 21:01:01,684 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #43

2017-01-12 21:01:01,684 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 2ms

2017-01-12 21:01:02,185 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #44

2017-01-12 21:01:02,186 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #44

2017-01-12 21:01:02,186 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 1ms

2017-01-12 21:01:02,187 DEBUG type (ApplicationMaster.java:onContainersCompleted) - Aborted container container_1484252891624_0004_01_000086

2017-01-12 21:01:02,687 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #45

2017-01-12 21:01:02,688 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #45

2017-01-12 21:01:02,688 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 1ms

2017-01-12 21:01:03,190 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #46

2017-01-12 21:01:03,193 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #46

2017-01-12 21:01:03,193 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 3ms

2017-01-12 21:01:03,695 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #47

2017-01-12 21:01:03,696 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #47

2017-01-12 21:01:03,696 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 2ms

2017-01-12 21:01:04,197 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #48

2017-01-12 21:01:04,198 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #48

2017-01-12 21:01:04,198 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 2ms

2017-01-12 21:01:04,699 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #49

2017-01-12 21:01:04,700 DEBUG Client (Client.java:receiveRpcResponse) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn got value #49

2017-01-12 21:01:04,700 DEBUG ProtobufRpcEngine (ProtobufRpcEngine.java:invoke) - Call: allocate took 2ms

2017-01-12 21:01:05,200 DEBUG Client (Client.java:run) - IPC Client (702846463) connection to ip-10-253-194-85.ec2.internal/10.253.194.85:8030 from yarn sending #50

...

Andrew Audibert

unread,

Jan 12, 2017, 4:56:40 PM1/12/17

to Dan, Alluxio Users

Glad that resolved the problem. The slowness could be due to using relaxed locality when requesting workers from YARN, so YARN offers many containers that already have workers and must be rejected. If you're interested it might help to set relaxLocality to false instead of true in requestContainers.

Dan

unread,

Jan 12, 2017, 5:03:20 PM1/12/17

to Alluxio Users, max...@gmail.com

Ok, if I get a chance I will try that. For this change, should I open a PR for 1.3.0 code base or 1.4.0-RC3 ?

...

Andrew Audibert

unread,

Jan 12, 2017, 5:10:24 PM1/12/17

to Dan, Alluxio Users

For the race condition fix, target the "branch-1.4" branch. 1.4.0 is done taking contributions, but that way the fix can make it into 1.4.1 and master. Improving the speed would go to master since it isn't a bug fix.

--

Dan

unread,

Jan 13, 2017, 1:48:04 PM1/13/17

to Alluxio Users, max...@gmail.com

Opened a PR here. Also, this PR should be merged into 1.4.1 as well.

I'm also noticing that the Workers will occasionally drop and not come back. I was going to start another thread but had a QQ: was the AM suppose to bring back lost workers or is this a feature needing to be implemented?

Thanks,

Dan

...

Andrew Audibert

unread,

Jan 13, 2017, 2:44:57 PM1/13/17

to Dan, Alluxio Users

Thanks for the PRs! I think the one which adds support for starting the master outside of YARN is more of a feature than a bug fix, so it's better to keep it in master. We can discuss more in the pull request if it's important to make the PR to 1.4.1

There isn't currently any support for relaunching lost workers - this feature still needs to be implemented.

Cheers,

Andrew

--

Reply all

Reply to author

Forward

0 new messages