-
Type: Bug
-
Status: Closed (View Workflow)
-
Priority: Minor
-
Resolution: Done
-
Affects Version/s: 1.3.0
-
Fix Version/s: 1.6.0
-
Component/s: None
-
Labels:None
-
Environment:
1.3-rc3
-
Epic Link:
-
Sprint:Emu Sprint 1 (9/21-10/9)
7 node cluster with fresh install. On startup one of the nodes has these exceptions:
first instance
337 2015-09-15 09:40:26,530 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Rejected AppendRequest[term =5, leader=onos://10.128.30.12:9876, logIndex=1, logTerm=5, entries=[0], firstIndex=false, commitIndex=null]: Request entry term does not match local log. Local log term is 3. Replying with AppendRes ponse[status=OK, term=5, succeeded=false, logIndex=1] 338 2015-09-15 09:40:26,534 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Rejected AppendRequest[term =5, leader=onos://10.128.30.12:9876, logIndex=1, logTerm=5, entries=[0], firstIndex=false, commitIndex=null]: Request entry term does not match local log. Local log term is 3. Replying with AppendRes ponse[status=OK, term=5, succeeded=false, logIndex=1] 339 2015-09-15 09:40:26,539 | INFO | FelixStartLevel | ConsistentApplicationIdStore | 79 - org.onosproject.onos-core-dist - 1.3.0.SNAPSHOT | Started 340 2015-09-15 09:40:26,540 | INFO | FelixStartLevel | ConsistentIdBlockStore | 79 - org.onosproject.onos-core-dist - 1.3.0.SNAPSHOT | Started 341 2015-09-15 09:40:26,545 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Rejected AppendRequest[term =5, leader=onos://10.128.30.12:9876, logIndex=1, logTerm=5, entries=[0], firstIndex=false, commitIndex=null]: Request entry term does not match local log. Local log term is 3. Replying with AppendRes ponse[status=OK, term=5, succeeded=false, logIndex=1] 342 2015-09-15 09:40:26,550 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Synced entry does not match local log, removing incorrect entries 343 2015-09-15 09:40:26,551 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | doAppendEntries 344 java.lang.IndexOutOfBoundsException: Log index out of bounds 345 at net.kuujo.copycat.util.internal.Assert.index(Assert.java:114)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 346 at net.kuujo.copycat.state.internal.SnapshottableLogManager.removeAfter(SnapshottableLogManager.java:190)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 347 at net.kuujo.copycat.raft.ActiveState.doAppendEntries(ActiveState.java:195)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 348 at net.kuujo.copycat.raft.ActiveState.handleAppend(ActiveState.java:86)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 349 at net.kuujo.copycat.raft.ActiveState.append(ActiveState.java:49)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 350 at net.kuujo.copycat.raft.FollowerState.append(FollowerState.java:157)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 351 at net.kuujo.copycat.raft.RaftContext$$Lambda$159/331159152.apply(Unknown Source)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 352 at net.kuujo.copycat.raft.RaftContext.lambda$wrapCall$21(RaftContext.java:562)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 353 at net.kuujo.copycat.raft.RaftContext$$Lambda$109/1173896349.run(Unknown Source)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 354 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_25] 355 at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_25] 356 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_25] 357 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_25] 358 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_25] 359 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_25] 360 at java.lang.Thread.run(Thread.java:745)[:1.8.0_25]
and the second instance of this exception
512 2015-09-15 09:40:35,448 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Heartbeat timed out in 3938 milliseconds 513 2015-09-15 09:40:35,448 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Polling members [onos://10. 128.30.13:9876, onos://10.128.30.16:9876, onos://10.128.30.17:9876, onos://10.128.30.12:9876, onos://10.128.30.14:9876, onos://10.128.30.11:9876, onos://10.128.30.15:9876] 514 2015-09-15 09:40:35,449 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Received accepted poll from onos://10.128.30.16:9876 515 2015-09-15 09:40:35,450 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Received rejected poll from onos://10.128.30.17:9876 516 2015-09-15 09:40:35,450 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Received rejected poll from onos://10.128.30.14:9876 517 2015-09-15 09:40:35,450 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Received rejected poll from onos://10.128.30.15:9876 518 2015-09-15 09:40:35,450 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Received rejected poll from onos://10.128.30.11:9876 519 2015-09-15 09:40:36,848 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Synced entry does not match local log, removing incorrect entries 520 2015-09-15 09:40:36,848 | WARN | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | doAppendEntries 521 java.lang.IndexOutOfBoundsException: Log index out of bounds 522 at net.kuujo.copycat.util.internal.Assert.index(Assert.java:114)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 523 at net.kuujo.copycat.state.internal.SnapshottableLogManager.removeAfter(SnapshottableLogManager.java:190)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 524 at net.kuujo.copycat.raft.ActiveState.doAppendEntries(ActiveState.java:195)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 525 at net.kuujo.copycat.raft.ActiveState.handleAppend(ActiveState.java:86)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 526 at net.kuujo.copycat.raft.ActiveState.append(ActiveState.java:49)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 527 at net.kuujo.copycat.raft.FollowerState.append(FollowerState.java:157)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 528 at net.kuujo.copycat.raft.RaftContext$$Lambda$159/331159152.apply(Unknown Source)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 529 at net.kuujo.copycat.raft.RaftContext.lambda$wrapCall$21(RaftContext.java:562)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 530 at net.kuujo.copycat.raft.RaftContext$$Lambda$109/1173896349.run(Unknown Source)[71:org.onosproject.onlab-thirdparty:1.3.0.SNAPSHOT] 531 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_25] 532 at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_25] 533 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_25] 534 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_25] 535 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_25] 536 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_25] 537 at java.lang.Thread.run(Thread.java:745)[:1.8.0_25] 538 2015-09-15 09:40:41,070 | INFO | copycat-p0-1 | FollowerState | 71 - org.onosproject.onlab-thirdparty - 1.3.0.SNAPSHOT | onos://10.128.30.16:9876 - Heartbeat timed out in 4222 milliseconds