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.

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

2025-01-29 - Joplin Android extremely slow after deleting many conflicts #11745

Open
CoffeeHT opened this issue Jan 29, 2025 · 16 comments
Open
Labels
bug It's a bug high High priority issues sync sync related issue

Comments

@CoffeeHT
Copy link

CoffeeHT commented Jan 29, 2025

Operating system

Android

Joplin version

Joplin Mobile 3.2.7 (prod, android)

Desktop version info

No response

Current behaviour

I recently had over 20,000 entries in the conflicts, a great many of them from notes whose data seems to be strangely corrupted.

These notes are or have been repeatedly displayed briefly as newly changed, even though I haven't touched them in a very long time, and could have repeatedly created new entries in conflicts.

My goal was to delete this impenetrable mass of over 20,000 conflicts in order to be able to better observe which conflicts were newly created.

My impression is that I have to delete the conflicts in each instance of my Windows and Android apps individually.

For the Windows apps, this deletion seems to have worked as expected so far.

Unfortunately, my Android app did not survive this procedure so well.

Since then, it has been extremely slow and - despite activating Caffeine - seems to be unable to cope with synchronisation.

Normal searches and normal editing seem to work if you're very patient and wait a minute after each save, which normally seems to take a second.

In the error log, I find messages like

01-29T07:39:28: NoteEditor: CodeMirror error error:Cannot read properties of undefined (reading 'addEventListener'): {} 01-29T07:33:43: Cannot execute MATCH query: ": malformed MATCH expression: [*"] (code 1 SQLITE_ERROR[1]) 01-29T07:31:39: Cannot execute MATCH query: ": malformed MATCH expression: [*"] (code 1 SQLITE_ERROR[1]) 01-28T23:19:01: NoteEditor: CodeMirror error error:Cannot read properties of undefined (reading 'addEventListener'): {} 01-28T19:43:23: NoteEditor: CodeMirror error error:Cannot read properties of undefined (reading 'addEventListener'): {} 01-28T19:20:58: NoteEditor: CodeMirror error error:Cannot read properties of undefined (reading 'addEventListener'): {} 01-28T19:06:35: ResourceService::indexNoteResources: A change was recorded for a note that has been deleted: ef981822027149d5bd3c81bdfaed2ffa 01-28T19:06:35: ResourceService::indexNoteResources: A change was recorded for a note that has been deleted: eaeb74e8fd1c4f00832deab9bb093b4b 01-28T19:06:35: ResourceService::indexNoteResources: A change was recorded for a note that has been deleted: de577d8b226846bfb4ba6a9ffcb7ad71 01-28T19:06:35: ResourceService::indexNoteResources: A change was recorded for a note that has been deleted: fc810da2bdfb4b4b8f4e7e20c939e04b 01-28T19:06:35: ResourceService::indexNoteResources: A change was recorded for a note that has been deleted: 481aafad98744d4fad004215c664e9ff
... a.s.o.

Expected behaviour

All searches, saving processes, etc. in the Android app work as quickly and smoothly as before the conflict data was deleted.

Logs

@CoffeeHT CoffeeHT added the bug It's a bug label Jan 29, 2025
@CoffeeHT
Copy link
Author

Addendum:
Unfortunately, I have to correct myself:
The last two notes that I laboriously created in the Android app still have not arrived in the Windows app after more than 10 minutes. Unfortunately, I have no choice but to wait and see.

@CoffeeHT
Copy link
Author

CoffeeHT commented Jan 29, 2025

Workaround started:
It is very bad for my usual daily business processes if my Android Joplin app does not work fast and reliably enough.
That's why I created another (‘B’) main profile on my Android and started the resynchronisation from the Joplin Cloud.
Lesson learned:
The Joplin Android log file is not – as I thought – a log file only for the currently active profile.
It is a log file for all profiles. Here is the error log file that recorded the initial absence of the MasterKey in the new B main profile.
You can also see the old entries for the original main profile here.

[logs removed]

@CoffeeHT
Copy link
Author

CoffeeHT commented Jan 30, 2025

Perhaps these new error logs will help.
The presumably temporary errors caused by multiple switches between mobile networks and various WLANs can probably be ignored.
But perhaps other new error messages are relevant.

[logs removed]

personalizedrefrigerator added a commit to personalizedrefrigerator/joplin that referenced this issue Jan 30, 2025
This is a refactoring change (change made while looking into
laurent22#11745).
@personalizedrefrigerator
Copy link
Collaborator

personalizedrefrigerator commented Jan 30, 2025

  • Note 1: I can reproduce the "malformed MATCH expression" errors on desktop (for example, by searching for " test) — it seems to be a separate issue.
  • Note 2: The CodeMirror errors are specific to the Markdown editor and should also be unrelated. Edit: This (unrelated) error message should be fixed by Android: Fix error logged when opening the note editor #11761.

The "A change was recorded for a note that has been deleted" logs are likely the most relevant.

@CoffeeHT
Copy link
Author

CoffeeHT commented Feb 2, 2025

Workaround started

Workaround not really successful.

What I found very positive about this test is that I was able to continue working normally with my Windows and Linux apps during the test, because there seems to be no longer any ‘exclusive lock’.

Three days after starting this test, I realise that it has not been so successful that I can work properly with the Android app again.
In the first few days, the synchronisation status displays were available relatively quickly and the development of the displayed values seemed to make logical sense to me.
Then the messages ‘Some items can't be decrypted’ came back, the synchronisation status displays took longer and longer and the displayed values were no longer as meaningful. Last night, no values were displayed at all: the application crashed after about 45 minutes before it could display new synchronisation status.

Many normal functions such as searching, opening or saving a note take far too long. Changes saved in Android either do not arrive in Windows apps at all or only with an extreme delay.

[logs removed]
The latest error entry is timestamped
02-01T22:56:20
I don't think my nightly attempts to display the synchronisation status are visible in this log file.

@CoffeeHT
Copy link
Author

CoffeeHT commented Feb 3, 2025

Workaround started:

Second workaround started.

Back to square one with NextCloud.

There I don't have the option to share notes with my people anymore, but I also don't have the complexity of key management that you guys are trying to do in Joplin Cloud for sharing encrypted notes.

I exported a JEX export with the Windows app on my Win10 guest system from my Joplin Teams main account and imported it into a new profile in my NextCloud. I also use E2EE there.

So far, it looks good. Since there is no longer an ‘exclusive lock’, I have already started synchronising this data to a new profile in my Android and Windows apps on my new Win11 guest system.

This is what the synchronisation status of my sending Windows app on my Win10 guest system looked like a few minutes ago:

Anhänge - Nicht heruntergeladen: 0 - Wird heruntergeladen: 0 - Heruntergeladen und entschlüsselt: 0 - Heruntergeladen und verschlüsselt: 0 - Lokal erstellt: 8309 - Fehler: 0 - Synchronisationsstatus (Elemente synchronisiert / Elemente insgesamt) - Note: 8087/8087 - Folder: 531/531 - Resource: **2077**/8309 - Tag: 0/326 - NoteTag: 0/561 - Revision: 0/36 - Insgesamt: 10695/17850 - Im Konflikt: 0 - Zu löschen: 0

Image

@personalizedrefrigerator
Copy link
Collaborator

Update: The application slowness may be related to the DecryptionWorker: error for ... log messages — at least in the portion of the log I was inspecting, they seem to be logged multiple times per second.

Sample message
01-20T07:19:13: DecryptionWorker: error for: 1a9cd7de28f94b48afcd6f2bf5313bf6 (resources) Error: File does not exist (reading file chunk).
Code: ENOENT
Error: File does not exist (reading file chunk).
    at construct (native)
    at Wrapper (address at index.android.bundle:1:2827622)
    at construct (native)
    at _createSuperInternal (address at index.android.bundle:1:2826758)
    at call (native)
    at JoplinError (address at index.android.bundle:1:2827086)
    at ?anon_0_ (address at index.android.bundle:1:4015186)
    at next (native)
    at asyncGeneratorStep (address at index.android.bundle:1:840556)
    at _next (address at index.android.bundle:1:840813)
    at anonymous (address at index.android.bundle:1:840765)
    at tryCallTwo (address at InternalBytecode.js:1:1222)
    at doResolve (address at InternalBytecode.js:1:2541)
    at Promise (address at InternalBytecode.js:1:1318)
    at anonymous (address at index.android.bundle:1:840686)
    at apply (native)
    at readFileChunk (address at index.android.bundle:1:4015039)
    at ?anon_0_ (address at index.android.bundle:1:1576707)
    at next (native)
    at asyncGeneratorStep (address at index.android.bundle:1:846151)
    at _next (address at index.android.bundle:1:846406)
    at anonymous (address at index.android.bundle:1:846358)
    at tryCallTwo (address at InternalBytecode.js:1:1222)
    at doResolve (address at InternalBytecode.js:1:2541)
    at Promise (address at InternalBytecode.js:1:1318)
    at anonymous (address at index.android.bundle:1:846279)
    at apply (native)
    at read (address at index.android.bundle:1:1576645)
    at ?anon_0_ (address at index.android.bundle:1:1579112)
    at next (native)
    at asyncGeneratorStep (address at index.android.bundle:1:846151)
    at _next (address at index.android.bundle:1:846406)
    at anonymous (address at index.android.bundle:1:846358)
    at tryCallTwo (address at InternalBytecode.js:1:1222)
    at doResolve (address at InternalBytecode.js:1:2541)
    at Promise (address at InternalBytecode.js:1:1318)
    at anonymous (address at index.android.bundle:1:846279)
    at apply (native)
    at decodeHeaderSource_ (address at index.android.bundle:1:1579070)
    at ?anon_0_ (address at index.android.bundle:1:1575692)
    at next (native)
    at asyncGeneratorStep (address at index.android.bundle:1:846151)
    at _next (address at index.android.bundle:1:846406)
    at anonymous (address at index.android.bundle:1:846358)
    at tryCallTwo (address at InternalBytecode.js:1:1222)
    at doResolve (address at InternalBytecode.js:1:2541)
    at Promise (address at InternalBytecode.js:1:1318)
    at anonymous (address at index.android.bundle:1:846279)
    at apply (native)
    at decryptAbstract_ (address at index.android.bundle:1:1575612)
    at ?anon_0_ (address at index.android.bundle:1:1578329)
    at next (native)
    at asyncGeneratorStep (address at index.android.bundle:1:846151)
    at _next (address at index.android.bundle:1:846406)
    at tryCallOne (address at InternalBytecode.js:1:1180)
    at anonymous (address at InternalBytecode.js:1:1874)
    at apply (native)
    at anonymous (address at index.android.bundle:1:292943)
    at _callTimer (address at index.android.bundle:1:291894)
    at _callReactNativeMicrotasksPass (address at index.android.bundle:1:292038)
    at callReactNativeMicrotasks (address at index.android.bundle:1:294028)
    at __callReactNativeMicrotasks (address at index.android.bundle:1:154693)
    at anonymous (address at index.android.bundle:1:153777)
    at __guard (address at index.android.bundle:1:154531)
    at flushedQueue (address at index.android.bundle:1:153688)
    at invokeCallbackAndReturnFlushedQueue (address at index.android.bundle:1:153631)

@CoffeeHT
Copy link
Author

CoffeeHT commented Feb 3, 2025

Second workaround started.

The first upload of my JEX export to my NextCloud should be complete soon.

Details

Anhänge
Nicht heruntergeladen: 0
Wird heruntergeladen: 0
Heruntergeladen und entschlüsselt: 0
Heruntergeladen und verschlüsselt: 0
Lokal erstellt: 8310
Fehler: 0
Synchronisationsstatus (Elemente synchronisiert / Elemente insgesamt)
Note: 8092/8092
Folder: 536/536
Resource: 8310/8310
Tag: 326/326
NoteTag: 150/561
Revision: 0/70
Insgesamt: 17414/17895

Im Konflikt: 0
Zu löschen: 0

Image

@CoffeeHT
Copy link
Author

CoffeeHT commented Feb 3, 2025

The application slowness may be related to the DecryptionWorker: error for ... log messages — at least in the portion of the log I was inspecting, they seem to be logged multiple times per second.

I wouldn't be surprised.

I wonder if, if my production data works as expected with NextCloud, I should delete all shares between my Joplin Cloud accounts, then export a JEX for each account, delete all my data in JoplinCloud and switch off the E2EE for all my Joplin Cloud accounts.

After that, I could start over with a new import of all my JEX exports with a new E2EE, set up the shares again, and see if the problem occurs again.

@personalizedrefrigerator
Copy link
Collaborator

personalizedrefrigerator commented Feb 3, 2025

I currently suspect that the slowness is caused by a large number of "file not found" logs from this line:

this.logger().warn(`DecryptionWorker: error for: ${item.id} (${ItemClass.tableName()})`, error, item);

The file not found error is coming from here:

await this.encryptionService().decryptFile(encryptedPath, plainTextPath);

Here are two things I can try to do:

  • Handle the case where a .crypted file is not found in a better way. For example,
    • Log "file not found (item id)" rather than a longer message with a stack trace.
    • If there are many such errors, only log the first one or two of them.
    • (Easiest) Only log this particular error when debug logging is enabled.
  • Try to replicate this and determine why the .crypted files for the resources are missing.
    • This might take a while — I suspect that the issue is related to the automatic resource download setting, but I'm not certain.

Edited: Grammar.

@personalizedrefrigerator
Copy link
Collaborator

personalizedrefrigerator commented Feb 17, 2025

Note: If this was caused by logging a large amount of data, this may be fixed (by #11771, which is not in a mobile release yet).

@CoffeeHT
Copy link
Author

Status:

Fortunately, I can finally work productively again since I got my productive Joplin data back into my Managed NextCloud via JEX import. The fact that there seems to be no longer an ‘exclusive lock’ also helps a lot.

I use my productive Joplin data simultaneously from two Android apps, four Windows apps and two Linux apps. I have been patient and waited until all elements had been downloaded from the NextCloud and decrypted each time a new Joplin app was added. With the Android apps, this took several days each time.

Although all object IDs change with each JEX import, I now have a manual workaround to avoid this problem. My problem with changing object IDs is that I enter these IDs as ‘External Link’ into other tools such as my calendars and this information is no longer valid after a JEX import because all IDs change. My manual workaround is to copy the corresponding ‘External Link’ information into the content of notes. Thanks to Joplin's wonderful search function, this note can then be found by searching for this ID, even if the current object ID has changed again due to a JEX import. Some of my notes have already had four or more object IDs copied into their content in this way. Now I even write the date as timestamp in the note.

Assumptions:

My Joplin data in the Joplin Cloud had somehow become logically inconsistent. Maybe because I tried to fix conflicts manually, under the mistaken assumption that object IDs never change. But that can't be the only cause of the various problems. I also noticed that the problems often occurred with the notes in a folder whose contents were shared with other Joplin Cloud IDs. I was particularly surprised that I received many messages in connection with Joplin Cloud that I was sometimes unable to decrypt my own notes. Somehow this probably has to do with the presumably very complex key management that has to be carried out by Joplin in connection with the Joplin Cloud and the sharing of folders.

It could be that many or all logical inconsistencies were removed when the JEX export from the Joplin cloud and the subsequent JEX import into my NextCloud were carried out, precisely because all object IDs change in the process. Since the JEX import into my Next Cloud, I no longer have any such problems and I have not experienced any data loss so far.

Plan:

I don't want to touch the data of my various Joplin Cloud IDs again until new versions of the Android app, the Windows app and the Linux app are available that have a chance of working well enough. Then I would proceed as follows:
a) remove all ‘share folders’ permissions.
b) then perform a JEX export of all Joplin Cloud IDs.

After that, I see two alternative approaches for how to proceed.

The reason for this distinction is that unfortunately there is no function to delete all data in the Joplin Cloud in a controlled manner if you, as the owner of the data, want to do so.

Approach I: Keep my existing Joplin Cloud IDs
c1) then completely delete all notes from all my Joplin Cloud IDs – including from the trash
d1) then disable E2EE
e1) then wait some time until I can assume that all data in Joplin Cloud has really been deleted
f1) refill all Joplin Cloud IDs with the current JEX exports and the new E2EE imports
g1) Allow several days for all apps on all of my Joplin Cloud IDs to be fully synchronised and for current changes to be synchronised quickly and accurately between the various apps.
h1) After that, share the designated folders with the other IDs again (read only), wait until all the synchronisation processes triggered by this are complete, and then check whether all new changes between the various apps of all Joplin Cloud IDs involved are synchronised quickly and without errors.
j1) Only when this state has been properly achieved will I hand the various Joplin Cloud accounts back to my people.

But maybe that's not a good idea at all. The following approach would probably be more reliable:

Approach II: Working with new Joplin Cloud IDs and cancelling the old IDs:
c2) Cancel all my existing (2 Team and 4 Basic) Joplin Cloud accounts.
d2) Create 6 new email addresses (redirects) for new Joplin Cloud IDs
e2) Create 6 new (2 Team and 4 Basic) Joplin Cloud accounts
f2) Fill all new Joplin Cloud accounts with imports of current JEX exports and new E2EE
g2) Allow a few days for all apps on all of my Joplin Cloud IDs to fully synchronise and for current changes to be synchronised quickly and accurately between the various apps.
h2) Then share the designated folders with the other IDs again (read only), wait until all the synchronisation processes triggered by this are complete, and then check whether all changes between the various apps of all Joplin Cloud IDs involved are synchronised quickly and without errors.
j2) Only when this condition has been properly achieved will I hand the various new Joplin Cloud accounts back to my people.

@personalizedrefrigerator
Copy link
Collaborator

Thank you for providing a status update! I've left a few comments. @laurent22 may further insights.

After that, I see two alternative approaches for how to proceed.

Related note: The Android 3.3.3 pre-release includes #11771, which may resolve this issue.

The reason for this distinction is that unfortunately there is no function to delete all data in the Joplin Cloud in a controlled manner if you, as the owner of the data, want to do so.

One option here might be @laurent22's Victor plugin should clear all data, then sync. This may be an alternative to "Approach I".

Although all object IDs change with each JEX import

I'm linking a related (unmerged) commit that should change this behavior: personalizedrefrigerator@341cd69. This commit updates the JEX and RAW import behavior to change item IDs only if the IDs are already in use. I hope to do further testing before converting this commit to a pull request.

@CoffeeHT
Copy link
Author

Thank you for your informative response to my status report!

Yes, the Victor plugin seems to offer exactly the functionality I was looking for. I think that with it, I can do without my Approach II. I also find your commit exciting.

Fortunately, I'm not under any time pressure to return to the Joplin Cloud at the moment, so I can take my time to think about it and take care of my day-to-day activities with my current configuration.

@personalizedrefrigerator
Copy link
Collaborator

I'm linking a related (unmerged) commit that should change this behavior: personalizedrefrigerator@341cd69. This commit updates the JEX and RAW import behavior to change item IDs only if the IDs are already in use. I hope to do further testing before converting this commit to a pull request.

Note from a discussion with @laurent22 — preserving note IDs while importing from JEX might cause issues in other parts of the app and with sync, so we probably won't support this for now.

@CoffeeHT
Copy link
Author

preserving note IDs while importing from JEX might cause issues in other parts of the app and with sync, so we probably won't support this for now.

understood

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug It's a bug high High priority issues sync sync related issue
Projects
None yet
Development

No branches or pull requests

2 participants