Skip to content
This repository has been archived by the owner on Aug 23, 2020. It is now read-only.

Analyzing entry points takes too long #1797

Closed
GalRogozinski opened this issue Mar 16, 2020 · 3 comments · Fixed by #1843
Closed

Analyzing entry points takes too long #1797

GalRogozinski opened this issue Mar 16, 2020 · 3 comments · Fixed by #1843
Assignees
@kwek20
Labels
C-Local Snapshots L-Requires Further Investigation T-Bug
Milestone
Mardi Gras

Comments

@GalRogozinski
Copy link
Contributor

Bug description

When taking local snapshots it takes a long time to analyze them

IRI version

1.8.4

Hardware Spec

Hetzner CX51

Steps To Reproduce

  1. Take a local snapshot
  2. See that the analyzing solid milestones step takes a long time

Expected Behaviour

Analyzing solid milestones should finish up quickly

Actual behaviour

Analyzing solid milestones takes a long time

Possible solutions

  1. Quick: just change the default on the local snapshot interval config so it won't happen
  2. Find the root cause
@tylerw1369
Copy link

This is what it shows on my node when I disable snapshots and it never gets sync. So in order to stop the long analyzing milestones I have to enable snapshots and make the snapshot taking between more milestones.

ar 16 09:02:38 tyler-node IRI[32571]: ... 14 common frames omitted
Mar 16 09:02:43 tyler-node IRI[32571]: 03/16 09:02:43.408 [Tips Requester] INFO TipsRequesterImpl:86 - toProcess = 0 , toBroadcast = 0 , toRequest = 0 , toReply = 0 / totalTransactions = 43359603
Mar 16 09:02:43 tyler-node IRI[32571]: 03/16 09:02:43.586 [Latest Solid Milestone Tracker] INFO LatestSolidMilestoneTrackerImpl:392 - Latest SOLID milestone index changed from #1348004 to #1348005
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.185 [Latest Solid Milestone Tracker] INFO MilestoneServiceImpl:534 - resetting corrupted milestone #1348009
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.232 [Latest Solid Milestone Tracker] INFO MilestoneServiceImpl:534 - resetting corrupted milestone #1348008
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.334 [Latest Solid Milestone Tracker] INFO MilestoneServiceImpl:534 - resetting corrupted milestone #1348007
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.465 [Latest Solid Milestone Tracker] INFO MilestoneServiceImpl:534 - resetting corrupted milestone #1348006
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.629 [Latest Solid Milestone Tracker] INFO MilestoneServiceImpl:534 - resetting corrupted milestone #1348005
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.748 [Latest Solid Milestone Tracker] INFO MilestoneServiceImpl:534 - resetting corrupted milestone #1348004
Mar 16 09:02:44 tyler-node IRI[32571]: 03/16 09:02:44.958 [Latest Solid Milestone Tracker] ERROR LatestSolidMilestoneTrackerImpl:465 - error while updating the solid milestone
Mar 16 09:02:44 tyler-node IRI[32571]: com.iota.iri.service.milestone.MilestoneException: unexpected error while checking for new latest solid milestones
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.LatestSolidMilestoneTrackerImpl.trackLatestSolidMilestone(LatestSolidMilestoneTrackerImpl.java:183) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.LatestSolidMilestoneTrackerImpl.latestSolidMilestoneTrackerThread(LatestSolidMilestoneTrackerImpl.java:207) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.utils.thread.BoundedScheduledExecutorService.lambda$wrapTask$6(BoundedScheduledExecutorService.java:585) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[na:na]
Mar 16 09:02:44 tyler-node IRI[32571]: at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[na:na]
Mar 16 09:02:44 tyler-node IRI[32571]: at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na]
Mar 16 09:02:44 tyler-node IRI[32571]: at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
Mar 16 09:02:44 tyler-node IRI[32571]: at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
Mar 16 09:02:44 tyler-node IRI[32571]: at java.base/java.lang.Thread.run(Thread.java:830) ~[na:na]
Mar 16 09:02:44 tyler-node IRI[32571]: Caused by: com.iota.iri.service.milestone.MilestoneException: failed to repair corrupted milestone with index #1348004
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.MilestoneServiceImpl.resetCorruptedMilestone(MilestoneServiceImpl.java:546) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.MilestoneServiceImpl.resetCorruptedMilestone(MilestoneServiceImpl.java:148) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.LatestSolidMilestoneTrackerImpl.repairCorruptedMilestone(LatestSolidMilestoneTrackerImpl.java:382) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.LatestSolidMilestoneTrackerImpl.applySolidMilestoneToLedger(LatestSolidMilestoneTrackerImpl.java:233) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.LatestSolidMilestoneTrackerImpl.trackLatestSolidMilestone(LatestSolidMilestoneTrackerImpl.java:170) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: ... 8 common frames omitted
Mar 16 09:02:44 tyler-node IRI[32571]: Caused by: com.iota.iri.service.snapshot.SnapshotException: failed to rollback last milestone
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.snapshot.impl.SnapshotServiceImpl.rollbackLastMilestone(SnapshotServiceImpl.java:375) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.snapshot.impl.SnapshotServiceImpl.rollBackMilestones(SnapshotServiceImpl.java:180) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.milestone.impl.MilestoneServiceImpl.resetCorruptedMilestone(MilestoneServiceImpl.java:539) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: ... 12 common frames omitted
Mar 16 09:02:44 tyler-node IRI[32571]: Caused by: com.iota.iri.service.snapshot.SnapshotException: failed to apply patch belonging to milestone #1348004 (CEBFZ9UXHMJY9ONOMIGOQHVWSTUIZWBSXELF9GBFGKHZOCHWIVRINQ9BKKOUTHESM9YTQAMDHKXU99999)
Mar 16 09:02:44 tyler-node IRI[32571]: at com.iota.iri.service.snapshot.impl.SnapshotServiceImpl.rollbackLastMilestone(SnapshotServiceImpl.java:346) ~[iri-1.8.4-RELEASE.jar:1.8.4-RELEASE]
Mar 16 09:02:44 tyler-node IRI[32571]: ... 14 common frames omitted

@tylerw1369
Copy link

Also when I reenable snapshots it works right away and syncs like normal again.

@GalRogozinski GalRogozinski added this to the Mardi Gras milestone Mar 30, 2020
@DyrellC DyrellC mentioned this issue Apr 1, 2020
Merged
6 tasks
@GalRogozinski GalRogozinski changed the title Analyzing solid milestones takes too long Analyzing entry points takes too long Apr 21, 2020
@kwek20
Copy link
Contributor

kwek20 commented Apr 21, 2020

I will be testing this with the following db: https://dbfiles.iota.org/mainnet/iri/2020-04-20T00%3A00%3A10Z-COMPLETE.tar

@kwek20 kwek20 mentioned this issue Apr 28, 2020
Merged
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@kwek20 kwek20

Labels
C-Local Snapshots L-Requires Further Investigation T-Bug
Projects
None yet
Milestone
Mardi Gras
Development

Successfully merging a pull request may close this issue.

[Fix] LS taking too long kwek20/iri
3 participants
@kwek20 @GalRogozinski @tylerw1369