Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Over 150 notes will cause S3 syncing to be stuck fetching #3591

Closed
alexchee opened this issue Aug 3, 2020 · 2 comments · Fixed by #3599
Closed

Over 150 notes will cause S3 syncing to be stuck fetching #3591

alexchee opened this issue Aug 3, 2020 · 2 comments · Fixed by #3599
Labels
bug It's a bug

Comments

@alexchee
Copy link
Contributor

alexchee commented Aug 3, 2020

Using AWS S3 syncing with 130+ notes, would cause the synchronisation worker to get stuck fetching items. The notes are correctly uploaded to and downloaded from S3, but the app would be stuck fetching items step until app is quit.

Environment

Joplin version: Joplin 1.0.233
Platform: Window, Mac
OS specifics: Windows 10, MacOS 10.14.6

Steps to reproduce

  1. Enable AWS S3 (Beta) synchronization target
  2. Import/create 130+ notes
  3. Click on Synchronize button.

Describe what you expected to happen

The status should

  1. Created/Update local items
  2. Created/Updated remote items
  3. Deleted local items and remote items
  4. Fetched Items
  5. Complete

Logfile

2020-08-03 18:07:44: "Profile directory: /Users/alexchee/.config/joplin-desktop"
2020-08-03 18:07:44: "KeychainService: checking if keychain supported"
2020-08-03 18:07:44: "KeychainService: check was already done - skipping. Supported:", "1"
2020-08-03 18:07:44: "Client ID: 9ccfa5901316494e949b405da61459bb"
2020-08-03 18:07:44: "Trying to load 1 master keys..."
2020-08-03 18:07:44: "Loaded master keys: 1"
2020-08-03 18:07:44: "ResourceFetcher: Auto-add resources: Mode: auto"
2020-08-03 18:07:44: "ResourceFetcher: Auto-added resources: 0"
2020-08-03 18:07:44: "Trying to load 1 master keys..."
2020-08-03 18:07:44: "Loaded master keys: 1"
2020-08-03 18:07:45: "Trying to load 1 master keys..."
2020-08-03 18:07:45: "Loaded master keys: 1"
2020-08-03 18:07:45: "Trying to load 1 master keys..."
2020-08-03 18:07:45: "Loaded master keys: 1"
2020-08-03 18:07:45: "RevisionService::runInBackground: Starting background service with revision collection interval 600000"
2020-08-03 18:07:45: "DecryptionWorker: starting decryption..."
2020-08-03 18:07:46: "DecryptionWorker: completed decryption."
2020-08-03 18:07:49: "RevisionService::maintenance: Starting..."
2020-08-03 18:07:49: "RevisionService::maintenance: Service is enabled"
2020-08-03 18:07:49: "RevisionService::collectRevisions: Created revisions for 0 notes"
2020-08-03 18:07:49: "RevisionService::maintenance: Done in 348ms"
2020-08-03 18:07:54: "SearchEngine: Updating FTS table..."
2020-08-03 18:07:54: "SearchEngine: Updated FTS table in 1ms. Inserted: 0. Deleted: 0"
2020-08-03 18:07:55: "Preparing scheduled sync"
2020-08-03 18:07:55: "Starting scheduled sync"
2020-08-03 18:07:59: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:00: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:01: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:02: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:02: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:03: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:19: "ResourceService::indexNoteResources: Start"
2020-08-03 18:08:20: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:20: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:21: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:22: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:23: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:23: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:24: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:25: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:25: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:26: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:27: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:28: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:28: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:29: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:30: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:30: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:31: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:32: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:33: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:33: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:34: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:38: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:39: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:39: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:40: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:41: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:42: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:42: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:43: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:44: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:45: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:45: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:46: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:47: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:48: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:48: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:48: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:48: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:49: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:49: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:49: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:49: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:49: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:49: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:50: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:51: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:52: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:53: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:53: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:53: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"
2020-08-03 18:08:54: "BasicDelta: Report: {"timestamp":"2020-08-03T21:20:12.000Z","older":0,"newer":0,"equal":0}"

It seems to be stuck looping on the Basic Delta, I started a fork to try to figure it out. I checked if the FileApiDriver list is looping indefinitely, but it's only called once in the sync, when I added a log in that call.

Any guidance on where I should look?
@alexchee alexchee added the bug It's a bug label Aug 3, 2020
@laurent22
Copy link
Owner

I'd just add debugger or console statements around these BasicDelta calls to see what's calling them repeatedly.

@alexchee alexchee mentioned this issue Aug 4, 2020
Closed
@alexchee
Copy link
Contributor Author

alexchee commented Aug 4, 2020 •
edited
Loading

#3599 found out the issue. The updated_time was using javascript Date instead of a Unix timestamp. I needed to blow out my local and resync to get it working again.

@alexchee alexchee mentioned this issue Aug 4, 2020
Merged
laurent22 pushed a commit that referenced this issue Aug 7, 2020
@alexchee
All: Fixes #3591: Fixed sync fetching issue (#3599)
8c7a242
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug It's a bug
Projects
None yet
Milestone
No milestone
2 participants
@alexchee @laurent22