search

VeriBlock / nodecore-releases

Other
37 stars 11 forks source link

[Nodecore v0.2.9] State stuck with: Present state: Stale #94

Closed Hou5e closed 6 years ago

Hou5e commented 6 years ago

After a restart and waiting for the blockchain to finish syncing, these messages occurred more often. Nodecore did sync and continue to add current blocks, but it's still stuck in the 'Stale' state when it really probably shouldn't be. It is good that it's informing you of a problem though.

Nodecore doesn't try to update or fix its status, even after 10 hours since the stale state started. The network connection being completely saturated at that time of day is probably what started this state.

It looks like this state started with multiple: Setting network state stale...

2018-08-06 13:25:42,625 INFO [grpc-default-executor-42] n.d.k [PeerEventListener.java:74] Add block 0000000001BF3A181E75153B4B62C71F20C024F5FDDC817C @ 64105 received from 18.191.139.75
2018-08-06 13:25:42,625 INFO [grpc-default-executor-42] n.core.a.n [DefaultBlockchain.java:1714] Has not seen 0000000001BF3A181E75153B4B62C71F20C024F5FDDC817C
2018-08-06 13:25:42,625 INFO [grpc-default-executor-39] n.d.b.b [PeerReconcileJob.java:71] Setting network state stale...
2018-08-06 13:25:42,625 INFO [grpc-default-executor-39] n.d.b.b [PeerReconcileJob.java:80] Starting peer reconcile job!
2018-08-06 13:25:42,625 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:87] Running peer reconcile job!
2018-08-06 13:25:42,625 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:90] First: 0000000012CC67437013DAEC1B0299F0AC3D676D7DF9AD8C
2018-08-06 13:25:42,625 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:95] Last: 0000000001F64C4A36AAC20DDA32395B152ADF87453BDC5C @ 64104
2018-08-06 13:25:42,625 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:154] Testing block '0000000001F64C4A36AAC20DDA32395B152ADF87453BDC5C' at height 64104
2018-08-06 13:25:42,626 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:169] Sent test...
2018-08-06 13:25:42,626 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:99] Sent query!
2018-08-06 13:25:42,626 INFO [ForkJoinPool.commonPool-worker-11] n.d.b.b [PeerReconcileJob.java:102] Waiting...

Then, these messages occurred more often: NodeCore blockchain state is now: Stale

2018-08-06 13:32:07,210 INFO [grpc-default-executor-39] n.d.k [PeerEventListener.java:74] Add block 0000000000FE628E80E9EE4A814F607488CB5BA9F462741C @ 64681 received from 148.251.42.76
2018-08-06 13:32:07,253 INFO [pool-23-thread-1] n.d.b.c [SyncJob.java:139] Expected more blocks from sync peer within 60 seconds and did not receive
2018-08-06 13:32:07,253 INFO [pool-23-thread-1] n.d.b.c [SyncJob.java:148] 81 blocks downloaded in batch from 94.130.239.46
2018-08-06 13:32:07,253 INFO [pool-23-thread-1] n.d.b.c [SyncJob.java:175] Did not received the expected batch size, ending job with current peer
2018-08-06 13:32:07,254 INFO [pool-23-thread-1] n.d.b.c [SyncJob.java:216] Completing sync with peer 94.130.239.46
2018-08-06 13:32:07,254 INFO [pool-23-thread-1] nodecore.h [NodeCoreState.java:76] NodeCore blockchain state is now: Stale
2018-08-06 13:32:07,254 INFO [pool-23-thread-1] n.core.a.n [DefaultBlockchain.java:380] Blockchain save started
2018-08-06 13:32:07,285 INFO [pool-23-thread-1] n.g.c [BetterFlatBlockchainRepository.java:244] Saving 1 blocks...
2018-08-06 13:32:07,285 INFO [pool-23-thread-1] n.g.c [BetterFlatBlockchainRepository.java:264] Reading file: /home/jeff/Desktop/VeriBlock/nodecore-0.2.9/bin/testnet/blocks/647.blk

It continues, and has an Issue #93, still with NodeCore blockchain state is now: Stale

2018-08-06 13:43:11,564 WARN [grpc-default-executor-46] n.d.k [PeerEventListener.java:101] Rejected transaction for reason: null
2018-08-06 13:43:11,568 WARN [grpc-default-executor-46] n.d.k [PeerEventListener.java:101] Rejected transaction for reason: null
2018-08-06 13:43:11,599 WARN [grpc-default-executor-46] n.d.k [PeerEventListener.java:382] Event stream error from 148.251.42.76: Status{code=CANCELLED, description=Failed to read message., cause=io.grpc.StatusRuntimeException: INTERNAL: Invalid protobuf byte sequence
    at io.grpc.Status.asRuntimeException(Status.java:517)
    at io.grpc.protobuf.lite.ProtoLiteUtils$MessageMarshaller.parse(ProtoLiteUtils.java:218)
    at io.grpc.protobuf.lite.ProtoLiteUtils$MessageMarshaller.parse(ProtoLiteUtils.java:118)
    at io.grpc.MethodDescriptor.parseResponse(MethodDescriptor.java:266)
    at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519)
    at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
    at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: com.google.protobuf.InvalidProtocolBufferException: While parsing a protocol message, the input ended unexpectedly in the middle of a field.  This could mean either that the input has been truncated or that an embedded message misreported its own length.
    at com.google.protobuf.InvalidProtocolBufferException.truncatedMessage(InvalidProtocolBufferException.java:86)
    at com.google.protobuf.CodedInputStream$ArrayDecoder.pushLimit(CodedInputStream.java:1212)
    at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:909)
    at nodecore.api.grpc.VeriBlockMessages$SignedTransaction.<init>(VeriBlockMessages.java:2536)
    at nodecore.api.grpc.VeriBlockMessages$SignedTransaction.<init>(VeriBlockMessages.java:2477)
    at nodecore.api.grpc.VeriBlockMessages$SignedTransaction$1.parsePartialFrom(VeriBlockMessages.java:3179)
    at nodecore.api.grpc.VeriBlockMessages$SignedTransaction$1.parsePartialFrom(VeriBlockMessages.java:3174)
    at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:911)
    at nodecore.api.grpc.VeriBlockMessages$TransactionUnion.<init>(VeriBlockMessages.java:15073)
    at nodecore.api.grpc.VeriBlockMessages$TransactionUnion.<init>(VeriBlockMessages.java:15017)
    at nodecore.api.grpc.VeriBlockMessages$TransactionUnion$1.parsePartialFrom(VeriBlockMessages.java:16001)
    at nodecore.api.grpc.VeriBlockMessages$TransactionUnion$1.parsePartialFrom(VeriBlockMessages.java:15996)
    at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:911)
    at nodecore.api.grpc.VeriBlockMessages$Block.<init>(VeriBlockMessages.java:27186)
    at nodecore.api.grpc.VeriBlockMessages$Block.<init>(VeriBlockMessages.java:27078)
    at nodecore.api.grpc.VeriBlockMessages$Block$1.parsePartialFrom(VeriBlockMessages.java:29261)
    at nodecore.api.grpc.VeriBlockMessages$Block$1.parsePartialFrom(VeriBlockMessages.java:29256)
    at com.google.protobuf.CodedInputStream$ArrayDecoder.readMessage(CodedInputStream.java:911)
    at nodecore.api.grpc.VeriBlockMessages$Event.<init>(VeriBlockMessages.java:46636)
    at nodecore.api.grpc.VeriBlockMessages$Event.<init>(VeriBlockMessages.java:46592)
    at nodecore.api.grpc.VeriBlockMessages$Event$1.parsePartialFrom(VeriBlockMessages.java:49106)
    at nodecore.api.grpc.VeriBlockMessages$Event$1.parsePartialFrom(VeriBlockMessages.java:49101)
    at com.google.protobuf.AbstractParser.parseFrom(AbstractParser.java:91)
    at com.google.protobuf.AbstractParser.parseFrom(AbstractParser.java:49)
    at io.grpc.protobuf.lite.ProtoLiteUtils$MessageMarshaller.parseFrom(ProtoLiteUtils.java:223)
    at io.grpc.protobuf.lite.ProtoLiteUtils$MessageMarshaller.parse(ProtoLiteUtils.java:215)
    ... 8 more
}
2018-08-06 13:43:11,599 INFO [grpc-default-executor-46] n.d.b.c [SyncJob.java:187] Aborting sync with peer 148.251.42.76
2018-08-06 13:43:11,600 INFO [grpc-default-executor-46] n.d.b.c [SyncJob.java:195] Job 867be8d4-2efd-449f-99fc-717a19dd469b has been canceled.
2018-08-06 13:43:11,600 ERROR [pool-27-thread-1] n.d.b.c [SyncJob.java:142] null
java.lang.InterruptedException: null
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
    at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
    at nodecore.d.b.c.g(SyncJob.java:129)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
2018-08-06 13:43:11,600 INFO [grpc-default-executor-46] nodecore.h [NodeCoreState.java:76] NodeCore blockchain state is now: Stale

Which eventually turns into this message once it catches up with the blockchain: Present state: Stale

2018-08-06 14:58:01,995 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:74] Add block 0000000000EFDBBDE3295B1D18A0F9DDC150F18F2507CC7B @ 68546 received from 88.99.249.217
2018-08-06 14:58:02,000 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:129] Heartbeat received from 88.99.249.217
2018-08-06 14:58:02,004 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:129] Heartbeat received from 88.99.249.217
2018-08-06 14:58:02,014 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:129] Heartbeat received from 88.99.249.217
2018-08-06 14:58:02,015 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:129] Heartbeat received from 88.99.249.217
2018-08-06 14:58:02,015 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:129] Heartbeat received from 88.99.249.217
2018-08-06 14:58:02,080 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:129] Heartbeat received from 148.251.42.76
2018-08-06 14:58:02,476 INFO [Thread-1] n.d.c [DefaultPeerHub.java:144] Watchdog sees local blockchain at height 68550 and the network is at 68550.
2018-08-06 14:58:02,476 INFO [Thread-1] n.d.c [DefaultPeerHub.java:145] Present state: Stale
2018-08-06 14:58:02,476 INFO [Thread-1] n.d.c [DefaultPeerHub.java:148] periodicPrune finished, found 0 sync/reconcile jobs, and pruned 0
2018-08-06 14:58:02,648 INFO [grpc-default-executor-85] n.d.k [PeerEventListener.java:74] Add block 00000000012596C0284824CCB7119420DB49D2A6DE330442 @ 68530 received from 94.130.238.199
JoshRack commented 6 years ago

Nearly all of the syncing code has changed since this version of the software.