[
https://issues.apache.org/jira/browse/YARN-2368?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14078954#comment-14078954
]
Leitao Guo commented on YARN-2368:
----------------------------------
Thanks [~ozawa] for your comments.
I deployed hadoop-2.3.0-cdh5.1.0 with 22-queue fairscheduler on my 20-node
cluster. Two resourcemanagers are deployed exclusively on 10.153.80.8 and
10.153.80.18.
Jobs are submitted from gridmix:
{code}
sudo -u mapred hadoop jar /usr/lib/hadoop-mapreduce/hadoop-gridmix.jar
-Dgridmix.min.file.size=10485760
-Dgridmix.job-submission.use-queue-in-trace=true
-Dgridmix.distributed-cache-emulation.enable=false -generate 34816m
hdfs:///user/mapred/foo/ hdfs:///tmp/job-trace.json
{code}
job-trace.json is generated by Rumen, with 6,000 jobs, average #maptasks per
job is 320 and average #reducetasks is 25.
I found 3 times (gridmix tested more than 3 times) that resourcemanager failed
when handle STATE_STORE_OP_FAILED event. At the same time, zookeeper throws out
'Len error IOException'
{code}
... ...
2014-07-24 21:00:51,170 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted
socket connection from /10.153.80.8:47135
2014-07-24 21:00:51,171 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client
attempting to renew session 0x247678daa88001a at /10.153.80.8:47135
2014-07-24 21:00:51,171 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:Learner@107] - Revalidating client:
0x247678daa88001a
2014-07-24 21:00:51,171 [myid:3] - INFO
[QuorumPeer[myid=3]/0.0.0.0:2181:ZooKeeperServer@595] - Established session
0x247678daa88001a with negotiated timeout 10000 for client /10.153.80.8:47135
2014-07-24 21:00:51,171 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@863] - got auth
packet /10.153.80.8:47135
2014-07-24 21:00:51,172 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@897] - auth success
/10.153.80.8:47135
2014-07-24 21:00:51,186 [myid:3] - WARN
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@354] - Exception
causing close of session 0x247678daa88001a due to java.io.IOException: Len
error 1813411
2014-07-24 21:00:51,186 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket
connection for client /10.153.80.8:47135 which had sessionid 0x247678daa88001a
... ...
2014-07-25 22:10:08,919 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted
socket connection from /10.153.80.8:50480
2014-07-25 22:10:08,921 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client
attempting to renew session 0x247684586e70006 at /10.153.80.8:50480
2014-07-25 22:10:08,922 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@595] - Established
session 0x247684586e70006 with negotiated timeout 10000 for client
/10.153.80.8:50480
2014-07-25 22:10:08,922 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@863] - got auth
packet /10.153.80.8:50480
2014-07-25 22:10:08,923 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@897] - auth success
/10.153.80.8:50480
2014-07-25 22:10:08,934 [myid:3] - WARN
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@354] - Exception
causing close of session 0x247684586e70006 due to java.io.IOException: Len
error 1530747
2014-07-25 22:10:08,934 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket
connection for client /10.153.80.8:50480 which had sessionid 0x247684586e70006
... ...
2014-07-26 02:22:59,627 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted
socket connection from /10.153.80.18:60588
2014-07-26 02:22:59,629 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client
attempting to renew session 0x2476de7c1af0002 at /10.153.80.18:60588
2014-07-26 02:22:59,629 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@595] - Established
session 0x2476de7c1af0002 with negotiated timeout 10000 for client
/10.153.80.18:60588
2014-07-26 02:22:59,630 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@863] - got auth
packet /10.153.80.18:60588
2014-07-26 02:22:59,630 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@897] - auth success
/10.153.80.18:60588
2014-07-26 02:22:59,648 [myid:3] - WARN
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@354] - Exception
causing close of session 0x2476de7c1af0002 due to java.io.IOException: Len
error 1649043
2014-07-26 02:22:59,648 [myid:3] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket
connection for client /10.153.80.18:60588 which had sessionid 0x2476de7c1af0002
{code}
> ResourceManager failed when ZKRMStateStore tries to update znode data larger
> than 1MB
> -------------------------------------------------------------------------------------
>
> Key: YARN-2368
> URL: https://issues.apache.org/jira/browse/YARN-2368
> Project: Hadoop YARN
> Issue Type: Bug
> Components: resourcemanager
> Affects Versions: 2.4.1
> Reporter: Leitao Guo
> Priority: Critical
> Attachments: YARN-2368.patch
>
>
> Both ResouceManagers throw out STATE_STORE_OP_FAILED events and failed
> finally. ZooKeeper log shows that ZKRMStateStore tries to update a znode
> larger than 1MB, which is the default configuration of ZooKeeper server and
> client in 'jute.maxbuffer'.
> ResourceManager (ip addr: 10.153.80.8) log shows as the following:
> {code}
> 2014-07-25 22:33:11,078 INFO
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore:
> ZKRMStateStore Session connected
> 2014-07-25 22:33:11,078 INFO
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore:
> ZKRMStateStore Session restored
> 2014-07-25 22:33:11,214 FATAL
> org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Received a
> org.apache.hadoop.yarn.server.resourcemanager.RMFatalEvent of type
> STATE_STORE_OP_FAILED. Cause:
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode
> = ConnectionLoss for
> /rmstore/ZKRMStateRoot/RMAppRoot/application_1406264354826_1645/appattempt_1406264354826_1645_000001
> at
> org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
> at
> org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1069)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore$8.run(ZKRMStateStore.java:926)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore$8.run(ZKRMStateStore.java:923)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore$ZKAction.runWithCheck(ZKRMStateStore.java:973)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore$ZKAction.runWithRetries(ZKRMStateStore.java:992)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore.existsWithRetries(ZKRMStateStore.java:923)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.ZKRMStateStore.updateApplicationAttemptStateInternal(ZKRMStateStore.java:620)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore.handleStoreEvent(RMStateStore.java:675)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore$ForwardingEventHandler.handle(RMStateStore.java:766)
> at
> org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore$ForwardingEventHandler.handle(RMStateStore.java:761)
> at
> org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:173)
> at
> org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:106)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> Meanwhile, ZooKeeps log shows as the following:
> {code}
> 2014-07-25 22:10:09,728 [myid:1] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] -
> Accepted socket connection from /10.153.80.8:58890
> 2014-07-25 22:10:09,730 [myid:1] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@832] - Client
> attempting to renew session 0x247684586e70006 at /10.153.80.8:58890
> 2014-07-25 22:10:09,730 [myid:1] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:Learner@107] - Revalidating
> client: 0x247684586e70006
> 2014-07-25 22:10:09,730 [myid:1] - INFO
> [QuorumPeer[myid=1]/0.0.0.0:2181:ZooKeeperServer@595] - Established session
> 0x247684586e70006 with negotiated timeout 10000 for client /10.153.80.8:58890
> 2014-07-25 22:10:09,730 [myid:1] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@863] - got auth
> packet /10.153.80.8:58890
> 2014-07-25 22:10:09,730 [myid:1] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@897] - auth
> success /10.153.80.8:58890
> 2014-07-25 22:10:09,742 [myid:1] - WARN
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@354] - Exception
> causing close of session 0x247684586e70006 due to java.io.IOException: Len
> error 1530
> 747
> 2014-07-25 22:10:09,743 [myid:1] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed
> socket connection for client /10.153.80.8:58890 which had sessionid
> 0x247684586e70006
> ... ...
> 2014-07-25 22:33:10,966 [myid:1] - WARN
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@354] - Exception
> causing close of session 0x247684586e70006 due to java.io.IOException: Len
> error 1530747
> {code}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
