[bug] Synchronization cannot make progress if rate limit occurs during sync chunks downloading

Describe the problem Quentier does not stop syncing. It starts to sync, reaches the API maximum, and when restarting gives this error.

QEverCloud/src/DurableService.cpp:193 [Warn] [durable_service]: Sync request getFilteredSyncChunk failed: EDAMSystemException: EDAMErrorCode::RATE_LIMIT_REACHED rateLimitDuration= 3520 sec.; request details: 
QEverCloud/src/DurableService.cpp:204 [Warn] [durable_service]: No retry attempts left
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2130 [Info] [quentier:main_window]: MainWindow::onRateLimitExceeded: seconds to wait = 3520
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2156 [Info] [quentier:main_window]: Evernote API rate limit exceeded, need to wait for 3520 seconds, the synchronization will continue at 21:01:32
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 159629, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 159629, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 159724, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 159724, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 159818, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 159818, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 159880, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 159880, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 159970, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 159970, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160114, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160114, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160188, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160188, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160273, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160273, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160360, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160360, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160444, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160444, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160535, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160535, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160627, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160627, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160727, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160727, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160790, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160790, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160869, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160869, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 160955, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 160955, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161045, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161045, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161137, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161137, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161249, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161249, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161320, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161320, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161502, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161502, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161553, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161553, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161721, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 161721, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 162020, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 162020, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 162046, highest server USN = 162046, last previous USN = 162046
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 162046, highest server USN = 162046, last previous USN = 162046

Then at some point it decides to go back to re=downloading the whole dataset again from the beginning, and the cycle continues. It has not been able to complete a sync.

Steps to reproduce the problem Steps to reproduce the behavior:

No idea.

Expected behavior That symc completes.

Environment info Please provide the information about the environment in which Quentier is run:

kubuntu 20.10
0.5.0-1~ppa~quentier~202103161852~ubuntu20.10.1
PPA

Additional context i have ~8300 notes, some of which have large attachments.

It appears you have encountered rate limit exceeding during the initial stage of synchronization - downloading the sync chunks. Currently there is no logic which would save the already downloaded sync chunks before trying the next attempt. Although at later stages of synchronization (when downloading bodies of notes and attachments) such logic is present because I expected most rate limiting issues to occur at those stages as note bodies and attachments are typically much heavier than data downloaded in sync chunks.

There is one thing you can try: revoke the authentication for your account before attempting to sync again. File -> Switch account -> Manage accounts -> choose your Evernote account and press "Revoke authentication" button. Then start the sync. You would be asked to authorize Quentier once again, after which the sync would start over. The thing is, Evernote temporarily raises the rate limit for recently authenticated clients so you might be able to at least download all the sync chunks and encounter the limit at a later stage where the logic preserving already downloaded stuff would kick in.

In any event, I realize now that rate limit exceeding can occur at this stage of sync too and some protection against redownloading the same stuff again and again is needed. Can't promise I'd be able to deliver it quickly but let's try the trick with authentication renewal first.

When i did this, it crashed

qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2203 [Warn] [quentier:main_window]: Received incorrect sync chunks download progress state: highest downloaded USN = 162046, highest server USN = 162046, last previous USN = 162046

qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2008 [Info] [quentier:main_window]: MainWindow::onSynchronizationStopped
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2008 [Info] [quentier:main_window]: MainWindow::onSynchronizationStopped
libquentier-r3S0bg/libquentier-0.5.0/src/synchronization/SynchronizationManager_p.cpp:1384 [Info] [synchronization]: Authentication datetime was not found within application settings, assuming it has never been written & launching the OAuth procedure
QObject: Cannot create children for a parent that is in a different thread.
(Parent is Breeze::WidgetStateEngine(0x565012a5b0b0), parent's thread is QThread(0x56501276c900), current thread is QThread(0x565014c68260)
QObject::installEventFilter(): Cannot filter events for objects in a different thread.
QObject: Cannot create children for a parent that is in a different thread.
(Parent is Breeze::WidgetStateEngine(0x565012a5b0b0), parent's thread is QThread(0x56501276c900), current thread is QThread(0x565014c68260)
QObject: Cannot create children for a parent that is in a different thread.
(Parent is Breeze::WidgetStateEngine(0x565012a5b0b0), parent's thread is QThread(0x56501276c900), current thread is QThread(0x565014c68260)
Dump path: /tmp/f4f1b4c4-8ccb-4793-dbc1c08c-4fa66783.dmp
Dump path: /tmp/f4f1b4c4-8ccb-4793-dbc1c08c-4fa66783.dmp
Illegal instruction (core dumped)

It should have shown a dialog with stack stace. Did it? If yes, it would be nice to see it. Otherwise the log mentions /tmp/f4f1b4c4-8ccb-4793-dbc1c08c-4fa66783.dmp, if you can, please attach this file here, maybe I could recover some information from it.

If you don't have unsaved local changes (which is unlikely given than you can't sync stuff from Evernote), you can also try to remove the persistence accumulated so far: remove ~/.quentier/EvernoteAccounts/<your account's folder> with all of its content. If you are afraid to lose something, you can e.g. archive it before removing the folder. And after this try to sync from the clean state again.

Alternatively you can try to authenticate again using an AppImage version of the app rather than the one from PPA. Maybe the crash is somehow related to showing the OAuth dialog. If so, it might work differently with another version of Qt - the one bundled with the AppImage.

And one more thing, from the crash log above I don't recognize parts about Breeze::WidgetStateEngine and its threading problems as parts of Quentier's code. It appears to be from some other part of your distro, possibly Qt platform plugin. If it's buggy, it might interfere with Quentier's functioning. So trying the AppImage (which comes with its own Qt version bundled in but without platform plugin) might help to figure out whether the problem comes from Quentier or from the environment in which it runs.

Actually I got an idea about the crash, don't try the AppImage yet, I'll try to do and experiment tomorrow and see whether my guess is correct.

Ran it again, re-authenticated, and now i am seeing something different

QEverCloud/src/DurableService.cpp:317 [Info] [durable_service]: Retrying async getNoteWithResultSpec request, 1 attempts left
QEverCloud/src/DurableService.cpp:285 [Warn] [durable_service]: Sync request getNoteWithResultSpec with id QUuid({46a26052-f44e-44cb-8aaa-b10d3ccc3860}) failed: EDAMSystemException: EDAMErrorCode::INTERNAL_ERROR 3ae6308ca28e9190f9b89a33641af5c6; request details: 
QEverCloud/src/DurableService.cpp:298 [Warn] [durable_service]: No retry attempts left
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2027 [Error] [quentier:main_window]: MainWindow::onSynchronizationManagerFailure: Caught EDAM system exception: error code = EDAMErrorCode::INTERNAL_ERROR: 3ae6308ca28e9190f9b89a33641af5c6
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2008 [Info] [quentier:main_window]: MainWindow::onSynchronizationStopped
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2008 [Info] [quentier:main_window]: MainWindow::onSynchronizationStopped
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2008 [Info] [quentier:main_window]: MainWindow::onSynchronizationStopped
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 505, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 656, highest server USN = 162046, last previous USN = 390

--- cut out uninteresting sync messages
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 162020, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 162046, highest server USN = 162046, last previous USN = 390

The sync is still hanging. So now what i think i am seeing is that it completes the initial chunk download, but that does not complete the sync.

Is there any kind of offline fsck function for local storage/cahce?

There is no fsck, the local storage is not a filesystem. I can't even think of much things which potentially could be checked and autocorrected while staying offline. It might help if you could share the whole logs. At least that way I could probably tell for sure how far the sync has actually gone this time. Given what you've already shared, I can tell that yes, the sync chunks have been downloaded successfully because note content is downloaded only after all the sync chunks are downloaded. EDAMSystemException with INTERNAL_ERROR error code means problems on Evernote's end according to their docs. So you might wait for some time and try again and it might work then. But I'll double check that it can't possibly be something on the client side.

I understand it is not a filesystem, by fsck i am thinking of checking consistency of the storage. i.e. the relationships (e.g. looking for orphans) and inconsistent records and references. What i am seeing now looks like it is related to inconsistencies in the local storage, or cached models (e.g. favorites) based on local storage.

When i run it with --logFile info, it starts up, and says is has all records, but does not have a full notebook list, when i try and show all notes sorted to show the latest note, it shows me the same list i saw before i reauthenticated. Then i sync it, and the ui hangs after the sync is complete. I can use the tray icon to quit, or kill the main window..

i am going to purge and start again from scratch.

Info logs below.

i don't have the crash logfile, but i will keep the next one.

QResource '/css/images/ui-icons_222222_256x240.png' not found or is empty
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2076 [Info] [quentier:main_window]: MainWindow::onAuthenticationFinished: success = true, error description = , account = Tim
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 505, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 656, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 1201, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 2511, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 3459, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 3860, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 4015, highest server USN = 162046, last previous USN = 390

-------- cut for brevity

qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161320, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161502, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161553, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 161721, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 162020, highest server USN = 162046, last previous USN = 390
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:2192 [Info] [quentier:main_window]: MainWindow::onSyncChunksDownloadProgress: highest downloaded USN = 162046, highest server USN = 162046, last previous USN = 390

QResource '/css/images/ui-icons_222222_256x240.png' not found or is emptyqt.qpa.xcb: internal error:  void QXcbWindow::setNetWmStateOnUnmappedWindow() called on mapped window
qt5-rSPNJO/quentier-qt5-0.5.0/bin/quentier/src/MainWindow.cpp:3501 [Info] [quentier:main_window]: MainWindow::onQuitRequestedFromSystemTrayIcon

From a quick glance at this log it seems the sync chunks are indeed successfully downloaded. If you have a large amount of stuff in your account, it can be expected that it takes some time to process the stuff from the sync chunks and GUI thread might feel unresponsive. If you give it some time, it might actually sort things out and continue with syncing notes. Given that you are able to quit from the tray icon I can conclude that GUI thread is not really stuck, it's just probably busy reacting on changes in the local storage as stuff from the sync chunks is being added to it. I'll laso try to find out if the sync could actually get stuck at this point somehow. In future when you share a comparatively large amount of logs, it's probably better to attach them as a file rather than paste in a comment.

Did a couple of things on this issue in both stable and unstable versions:

Fixed what I believe was the root cause of the crash during authentication attempt - OAuth now runs in GUI thread rather than in the synchronization thread
Promoted some more logs to info level for better understanding how much progress the sync has done.

Going further I believe #368 would be required to figure out whether sync gets stuck after sync chunks are downloaded or not. It would require some time to implement though.

Latest version did not crash when i re-authorised

When i say sync is "on" below, i mean that pressing sync button while "on" stops/cancels the sync operation. I am not sure if this is intended behavior. The sync stays active even when it does not process anything new. My expectation would be for it to turn "off" once the download completed and post-processing started.

Steps i took:

reset local storage

rm -rf .quentier* .local/share/quentier.org/ .local/share/RecentDocuments/quent* .cache/quentier.org/

start quentier, login and
press button to perform first sync (sync is now "on")
when sync hits first ratelimit, wait for restart
(first problem) when ratelimit lifts, sync restarts - it does not continue where it left off, it repeats step 3.
when step 5 hits ratelimit press sync button - turns sync "off". (at this point ~1/3 of my notes seem to be available)
revoke authentication,
press sync button, (sync is now on) and re-authenticate
wait for sync to complete, ~1/2 of my notes seem to be available.
press sync button, (t cancel sync)
press sync button, (sync is now on) and re-authenticate
wait for sync to complete, no changes to local database but seems to be stuck in 'downloaded' state.

pressing sync button while "on" stops/cancels the sync operation. I am not sure if this is intended behavior.

Yes, it is the intended behaviour.

The sync stays active even when it does not process anything new. My expectation would be for it to turn "off" once the download completed and post-processing started.

That's not how it works. The sync is considered active until everything downloaded is put into the local storage and then local changes (if any) are sent back to Evernote. There is not a single download stage during the sync process: first the so called sync chunks are downloaded: they contain data on notebooks, tags, saved searches and metadata of notes (no content or attachments) and, in case of incremental sync, metadata of attachments (no actual data, only its various attributes). Notes and attachments are downloaded separately then. It doesn't make sense to consider the sync inactive after the sync chunks are downloaded.

I'll check the behaviour on sync cancelling but if I remember correctly it should persist the smallest non-processed update sequence number so that it could start from it again. There's no guarantee it won't re-download some of the data due to how Evernote's sync protocol works.

wait for sync to complete, ~1/2 of my notes seem to be available.

press sync button, (t cancel sync)

Have you tried not canceling it until all of your notes are available?

wait for sync to complete, no changes to local database but seems to be stuck in 'downloaded' state.

Some slowness here can be expected. As I wrote above, due to how Evernote's sync protocol works if not everything was synced the last time, at least some of the already fetched data might have to be re-downloaded. When the same data is downloaded, the additional effort is required to figure out that the very same stuff is already present and nothing has really changed.

If you don't cancel the sync while it's in progress, are you able to sync all of your stuff provided that you revoked the authentication before starting the sync?

I will do a revoke and resync overnight and see what happens.

Revoked, synced with latest release.

So now its not crashing, but it is not progressing past 5/8ths of my notes.

Is it worth removing it all and trying again? or should i wait for a patch?

but it is not progressing past 5/8ths of my notes.

What are the absolute numbers? What do you mean "not progressing"? Do you get any error (like the one you mentioned here or does it just get stuck? If stuck, how long have you waited?

Have you tried to run the sync again after it was able to download something partially? Do you use stable or unstable version? I've implemented the progress reporting for sync chunks which you asked for in #368 but it's only in unstable version now. However, as long as you are getting to syncing the notes, progress reporting on sync chunks processing is irrelevant.

Please understand that I can only help you if you provide me with the detailed info. I need steps you are taking, I need absolute numbers, I need logs. Otherwise there's not much I can do.

Let me clarify some things a bit further.

Quentier is a piece of software consisting of tens of thousands of lines of code. Synchronization logic takes roughly several thousand lines. If something goes wrong with the sync, the first thing I need is to locate where that happens. There are several techniques for that but given that I cannot always reproduce the problem of every potential user on my own account's data, I made Quentier write logs. It can write logs with varying degree of detail. Your account is quite large (you mentioned about 8000 of notes) so in your case the default level of detail should be ok - not too much and not too little. In order to troubleshoot any issue that I cannot reproduce I need at least the logs. On Linux Quentier's logs are stored in ~/quentier/logs-quentier folder. Just grab the file and attach it to the comment. It's easy enough, is it?

If you don't give me the logs but just write in vague terms like "the sync is not progressing past 5/8th of my notes", I have no idea whatsoever what the cause of that can be given just these words. Could be anything. Now, you posted in another unrelated issue that now you are getting EDAMErrorCode::INTERNAL_ERROR on attempt to sync. I've already explained what that error code means - it means problems on Evernote's end. Quentier can't really do much about these problems. It already retries downloading on errors several times but it appears it doesn't help.

Now let me explain how Quentier tries to handle sync errors. Evernote dictates that the sync is performed according to a particular protocol. I'll spare you the details but the important thing is that Evernote orders everything in your account - notes, notebooks, tags, saved searches - with a number called "update sequence number". It's roughly a version of a piece of data in your account. Whenever you update some piece of data in your Evernote's account (via any Evernote client, Quentier or official or web, whatever), it gets assigned a new update sequence number. However, it's not just a "+1" to the previous update sequence number of this data item. Instead it is a number which is unique within your account. I.e. new update sequence number is last max update sequence number within the account + 1.

The deal with this update sequence number is as follows: when you sync for the first time from the clean state, you download everything from your account from the smallest to the largest update sequence number. But presumably you only do full sync once and then just get incremental updates. For this to happen, the client application needs to remember the last successfully synced update sequence number. Quentier does that in case of successful sync. But it also tries to do this in case of a failed sync. If sync has failed (and if the point of failure is after downloading the sync chunks - which include notebooks, tags, saved searches and only metadata of notes) Quentier looks at the data it hasn't downloaded, finds the smallest update sequence number of these data items and saves it in order to start the next sync attempt from this item. You can find this number in ~/.quentier/EvernoteAccounts/<your account's folder>/settings/SynchronizationPersistence.ini. It's called last_sync_update_count. This number could be used e.g. to understand whether the attempt to download the rest of the data after the first unfinished sync makes any progress at all: you now have a partially synced account. Look at this number, remember its value. Then try to sync again. Maybe the next sync attempt won't finish successfully either. But look at this number after such attempt: if it's increasing then something which was not downloaded for the first time was downloaded now.

The downside of this approach of update sequence number handling is that it might still result in re-downloading the data already processed during the previous sync attempt. When such re-download happens, the local storage detects that there's a potentially conflicting version already stored inside it, it needs to compare the two versions and figure out they are equivalent. If there are a lot of such re-downloaded data items within the account, it can explain the slowness you experience when trying to continue the unfinished first sync. However, to diagnose this I need logs. And I might need further information like what were your exact steps - it might be crucially important and make a difference between being able to diagnose and help and not being able to say anything at all on the issue.

I'm sorry if my tone sounds a bit rude but please understand: I need your cooperation in order to diagnose and fix this problem. At the very least I need the logs. When provided with them I might need other information. Also, when providing the logs, please attach them as files to comments, don't post them to comments. They are huge and make the comments overly lengthy.

Furthermore, which version of Quentier are you using - stable or unstable one? In unstable version I've added progress report during the sync between downloading them and starting the sync of notes. If you use unstable version, you can see this progress report during the sync in the status bar. It is also reflected in logs written by Quentier.

Also about what you can try now: I don't think it would be fruitful to try removing everything and trying to sync from scratch again. With account as large as yours the probability of things going wrong during the initial sync would be quite large. Instead I believe the more proper way forward would be to try syncing again after the first sync fails at some point. Previously you reported that in this case sync hangs after downloading the sync chunks. Well, I added progress reporting and logging for this stage of sync but currently only in unstable version. So if you use that, you can try it now. If you use a stable version, you can take the AppImage of unstable version and run it (after downloading you need to do chmod a+x on the file before running it). If something goes wrong, you are welcome to report further problems but please do it properly - read what I wrote above about the need for logs and other information.

Quentier could probably try harder to download as much as possible during the first run and then try to download the missing parts. It would be a violation of Evernote's sync protocol but from practical perspective it might work. Something like this:

If some notes fail to download with INTERNAL_ERROR or some other potentially retriable error, don't abort the sync momentarily, just set a flag that the sync is incomplete and add the guid of the note to the list of those which we failed to download
When other content is downloaded (as much as possible of it), persist the state of the sync: the fact that it was not complete and the list of what we failed to download.
When the sync is run the next time, detect the fact that the last sync was incomplete and try to complete it: try to download only the stuff which we failed to download the last time and not anything more. If that is successful, continue with regular sync.

This scheme might introduce some tricky cases if the period between the two syncs was large enough so that some stuff has changed since the last time: some note which we failed to download the last time no longer exists as it was deleted, some other note was updated and now has a different update sequence number, possibly a different list of tags (some of which might not yet exist locally). All of these edge cases need to be carefully thought out as otherwise they might break the sync even worse.

Furthermote, implementing something like this would take me months. So I suggest we try to troubleshoot the logic already implemented which I described above. The sync should be able to continue after the initial incomplete sync. In unstable version there's now progress reporting on the stage of sync after sync chunks downloading and before notes downloading so it should be possible to see whether it hangs there or not.

No problem for the rant, it is justified. I am habitually reticent with potentially personal information in a public forum, this is a potential situation where you need enough detail to isolate the issue, or separate out all of the issues my account brings up.

i downloaded the unstable appimage you linked to in the feature request #368. Initially i kept my current stable database, but it generated the SQL errors i posted to that issue.

I have since removed the storage and started an initial sync. I immediately saw some discrepancies, between the number of notes claimed by the UI, and the number claimed by the logs. So i need to go back to the beginning with better logging and make time to perform and post a better analysis of the issue, and include logs where appropriate.

I am habitually reticent with potentially personal information in a public forum

Ok, I can certainly understand that. However, info level logs most probably won't contain any kind of personal information. More verbose logs such as debug and trace ones can though. If you don't want to share your logs publicly, you can e-mail them to me. My e-mail is dm.vl.ivanov@gmail.com.

This fix did not work, and i do not have the time to do much more with Evernote (and hence quentier), as i am phasing it out. I have moved to the web and windows client under wine in an attempt to tidy up my Evernote repo. You can close this, i will test your fix again when i have tidied up my evernote, and before i remove the account. Thanks for the help, sorry i cannot spend more time with this corner case.

Ok, I created two other issues which should help in a a scenario like yours: d1vanov/libquentier#187 d1vanov/libquentier#188

Closing this one.

d1vanov / quentier

[bug] Synchronization cannot make progress if rate limit occurs during sync chunks downloading #367