text
text copied to clipboard
Content duplicates
I have gotten a report about a file content being duplicated. Checking the file and when this happend I've seen the following access log
Save highlighted and some possibly suspicious large pushs
- [26/Feb/2024:17:37:35 +0000] "PUT /apps/text/session/8319994/create HTTP/1.1" 200 2072 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 326482
- [26/Feb/2024:17:37:36 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 4561 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 298094
- [26/Feb/2024:17:37:36 +0000] "PUT /apps/text/session/8319994/create HTTP/1.1" 200 5425 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 262602
- [26/Feb/2024:17:37:37 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 4755 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 240192
- [26/Feb/2024:17:37:37 +0000] "POST /apps/text/session/8319994/close HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 258176
- [26/Feb/2024:17:37:37 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 4757 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 196571
- [26/Feb/2024:17:37:38 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 4523 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 306216
- [26/Feb/2024:17:37:38 +0000] "PUT /apps/text/session/8319994/create HTTP/1.1" 200 5464 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 81013
- [26/Feb/2024:17:37:39 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 69689
- [26/Feb/2024:17:37:39 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 45801
- [26/Feb/2024:17:37:39 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 4899 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 62027
- [26/Feb/2024:17:37:39 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 4561 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 81717
- [26/Feb/2024:17:37:39 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1224 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 66798
- [26/Feb/2024:17:37:39 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1224 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 328458
- [26/Feb/2024:17:37:40 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 279224
- [26/Feb/2024:17:37:41 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 2068 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 87629
- [26/Feb/2024:17:37:41 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 1742 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 307328
- [26/Feb/2024:17:37:42 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 104200
- [26/Feb/2024:17:37:42 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 2030 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 256682
- [26/Feb/2024:17:37:42 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 83362
- [26/Feb/2024:17:37:43 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 299109
- [26/Feb/2024:17:37:44 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1224 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 114591
- [26/Feb/2024:17:37:44 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 76026
- [26/Feb/2024:17:37:46 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1224 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 277595
- [26/Feb/2024:17:37:47 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 101590
- [26/Feb/2024:17:37:49 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1224 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 93880
- [26/Feb/2024:17:37:52 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1186 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 102879
- [26/Feb/2024:17:37:54 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1224 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 98642
- [26/Feb/2024:17:37:55 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 53642
- [26/Feb/2024:17:37:55 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 239371
- [26/Feb/2024:17:37:56 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 71583
- [26/Feb/2024:17:37:57 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 68970
- [26/Feb/2024:17:37:58 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1222 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 286465
- [26/Feb/2024:17:37:59 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1222 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 98738
- [26/Feb/2024:17:38:03 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1222 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 289593
- [26/Feb/2024:17:38:05 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1184 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 160587
- [26/Feb/2024:17:38:08 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 131273
- [26/Feb/2024:17:38:08 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 386638 - [26/Feb/2024:17:38:07 +0000] "POST /apps/text/session/8319994/save HTTP/1.1" 200 909 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 1555208
- [26/Feb/2024:17:38:09 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1181 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 101480
- [26/Feb/2024:17:38:09 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 243807
- [26/Feb/2024:17:38:10 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 259059
- [26/Feb/2024:17:38:10 +0000] "POST /apps/text/session/8319994/close HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 54200
- [26/Feb/2024:17:38:10 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 70175
- [26/Feb/2024:17:38:14 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1206 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 280950
- [26/Feb/2024:17:38:19 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1168 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 258116
- [26/Feb/2024:17:38:25 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 252346
- [26/Feb/2024:17:38:25 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1168 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 99631
- [26/Feb/2024:17:38:30 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1206 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 94824
- [26/Feb/2024:17:38:36 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1206 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 104128
- [26/Feb/2024:17:38:40 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 842 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 63247
- [26/Feb/2024:17:38:41 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1055 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 281592
- [26/Feb/2024:17:38:47 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1055 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 77930
- [26/Feb/2024:17:38:52 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1055 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 98535
- [26/Feb/2024:17:38:55 +0000] "POST /apps/text/session/8319994/push HTTP/1.1" 200 804 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 253980
- [26/Feb/2024:17:38:57 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1170 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 82322
- [26/Feb/2024:17:39:03 +0000] "POST /apps/text/session/8319994/sync HTTP/1.1" 200 1170 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:121.0) Gecko/20100101 Firefox/121.0" 296501
Looks a bit suspicious, maybe this is related to the file opening process in some way.
FYI @max-nextcloud @mejo-
Just an idea, with some questions that might be worth to investigate:
- Could there be a race condition when multiple sessions initialize a session where we initially set the content of the y.js doc which then could lead to two steps being pushed with the initial document source?
- Probably worth to check here https://github.com/nextcloud/text/blob/enh/vite/src/components/Editor.vue#L540
- Can we check on the backend side if the step that is being pushed is such a initial one (so we could just skip any second)?
I recently encountered this as well (on 27.1.6). Unfortunately I didn't have time to debug in that very moment. In case it happens again, probably a backup of the steps in the database could be helpful, right?
We can confirm, at least with 28.0.2, probably also 28.0.3.
Managed to reproduce by:
- Open a document
- Manually drop the entry from oc_text_documents
- Reload the page
Steps seem to be still in the steps file and then reapply on top of the new base document
A fix for a possible case is in #5470 however I currently cannot see other code paths that could lead to this
Other code path to check https://github.com/nextcloud/text/blob/9412ae1f2afb6db81c4465a81032e6697bf7cf73/lib/Service/ApiService.php#L139-L159
Other code path to check
We discussed this today and it looks like this code path is indeed the culprit:
- When all sessions are closed the document table entry is removed but the yjs file remains in case someone reopens their laptop and wants to continue the session.
- Someone creates a new session and the document is loaded from the markdown ( first if block).
- Next person comes around before the doc has been autosaved. Now a document entry exists again - therefore fresh session is false and the content of the yjs state file is send out instead.
- The two clients communicate and combine the content they both loaded via different mechanisms
- content duplicate.
This should hopefully be fixed now with all the pieces from https://github.com/nextcloud/text/issues/5476#issuecomment-2010155145
In which Nextcloud versions is that bug fixed? I still see a similar symptom in Nextcloud 27.1.10 with Text 3.8.0 (I first noticed it after the update to 27.1.9, but it might have been there already).
Are there any manual steps required or helpful to resolve the issue and get into a clean state?
What I see that sometimes when I download the file the content is correct (only once). But content displayed in the editor (and above the file listing) is duplicate. Sometimes the duplicate content is saved to the file. I experimented with moving appdata_xyz/text/documents/ and after scan-app-data (IIRC) some files showed the content three times.
@bugspencor thanks for your heads up. Let me ask you some questions first before I reply to yours...
Questions
- Are you seeing this with folder descriptions only (Readme.md) or also with other files?
- Do you have a file with duplicate content that has not been saved to the file yet?
Could you make sure the file does not contain private content and provide us with a database excerpt for that file?
You'd need to run the following query on your database:
SELECT * FROM oc_text_steps WHERE document_id=723(replacing 723 with the file-id in question)
Answering your questions
In which Nextcloud versions is that bug fixed? I still see a similar symptom in Nextcloud 27.1.10 with Text 3.8.0 (I first noticed it after the update to 27.1.9, but it might have been there already).
The fixes are included in https://github.com/nextcloud/text/pull/5543 and were merged in 27.1.9.
Are there any manual steps required or helpful to resolve the issue and get into a clean state?
You can clear all the current editing sessions with
occ text:reset [file-id]
Editing sessions are long running to allow reconnects when users open their laptop after a while again.
What I see that sometimes when I download the file the content is correct (only once). But content displayed in the editor (and above the file listing) is duplicate.
That state will be fixed by running the above command for the file in question
Sometimes the duplicate content is saved to the file.
In this case the command won't make any difference.
@max-nextcloud thanks for the comment. To answer your questions:
- this happens with other non-Readme.md files, too
- I have one example with the default Documents/Readme.md (I did not find another non-Readme.md which is not saved with duplicate content and does not contain private information, if that's required let me know, then I'll search more thoroughly):
# mariadb nextcloud -B -e "SELECT * FROM oc_text_steps WHERE document_id=433709"
id document_id session_id data version
4526 433709 1110 ["AAKUAgEKzKaluAUABwEHZGVmYXVsdAMHaGVhZGluZwcAzKaluAUABgQAzKaluAUBCURvY3VtZW50cygAzKaluAUABWxldmVsAX0BKADMpqW4BQACaWQBfygAzKaluAUABHV1aWQBf4fMpqW4BQADCXBhcmFncmFwaAcAzKaluAUOBgQAzKaluAUPek5leHRjbG91ZCB3b3JrcyB3ZWxsIHdpdGggYWxsIHRoZSBjb21tb24gZG9jdW1lbnQgZm9ybWF0cy4gWW91IGNhbiBldmVuIGNvbGxhYm9yYXRlIHdpdGggb3RoZXJzIG9uIE9EVCBhbmQgTWFya2Rvd24gZmlsZXMhh8ympbgFDgMJcGFyYWdyYXBoAA==","AAJVAQLMpqW4BYsBqMympbgFDAF3C2gtZG9jdW1lbnRzqMympbgFDQF3JDU1NDFlMTFiLTEzYjEtNGJlNy1hMzc2LTFjOWZhOWJiZGJmMQHMpqW4BQEMAg=="] 2147483647
8047 433709 2626 ["AALsAQEKAAAHAQdkZWZhdWx0AwdoZWFkaW5nBwAAAAYEAAABCURvY3VtZW50cygAAAAFbGV2ZWwBfQEoAAAAAmlkAX8oAAAABHV1aWQBf4cAAAMJcGFyYWdyYXBoBwAADgYEAAAPek5leHRjbG91ZCB3b3JrcyB3ZWxsIHdpdGggYWxsIHRoZSBjb21tb24gZG9jdW1lbnQgZm9ybWF0cy4gWW91IGNhbiBldmVuIGNvbGxhYm9yYXRlIHdpdGggb3RoZXJzIG9uIE9EVCBhbmQgTWFya2Rvd24gZmlsZXMhhwAOAwlwYXJhZ3JhcGgA","AAJIAQLM3ZGPDgCoAAwBdwtoLWRvY3VtZW50c6gADQF3JGE2OTMzYWI3LTY0NjktNDRhYS04ZjM0LTBlNGU4YjgzYjdkMwEAAQwC"] 2147483647
8048 433709 2626 ["AAIrAQHM3ZGPDgKozKaluAWLAQF3DmgtZG9jdW1lbnRzLS0xAcympbgFAYsBAQ=="] 2147483647
8051 433709 2638 ["AALsAQEKAAAHAQdkZWZhdWx0AwdoZWFkaW5nBwAAAAYEAAABCURvY3VtZW50cygAAAAFbGV2ZWwBfQEoAAAAAmlkAX8oAAAABHV1aWQBf4cAAAMJcGFyYWdyYXBoBwAADgYEAAAPek5leHRjbG91ZCB3b3JrcyB3ZWxsIHdpdGggYWxsIHRoZSBjb21tb24gZG9jdW1lbnQgZm9ybWF0cy4gWW91IGNhbiBldmVuIGNvbGxhYm9yYXRlIHdpdGggb3RoZXJzIG9uIE9EVCBhbmQgTWFya2Rvd24gZmlsZXMhhwAOAwlwYXJhZ3JhcGgA","AAJIAQLd8JrOCwCoAAwBdwtoLWRvY3VtZW50c6gADQF3JGM5NzljMmRhLWUyNGUtNGZjYi04YmRlLWYzYmUxZmIwZmE1ZAEAAQwC"] 2147483647
8052 433709 2641 ["AALsAQEKAAAHAQdkZWZhdWx0AwdoZWFkaW5nBwAAAAYEAAABCURvY3VtZW50cygAAAAFbGV2ZWwBfQEoAAAAAmlkAX8oAAAABHV1aWQBf4cAAAMJcGFyYWdyYXBoBwAADgYEAAAPek5leHRjbG91ZCB3b3JrcyB3ZWxsIHdpdGggYWxsIHRoZSBjb21tb24gZG9jdW1lbnQgZm9ybWF0cy4gWW91IGNhbiBldmVuIGNvbGxhYm9yYXRlIHdpdGggb3RoZXJzIG9uIE9EVCBhbmQgTWFya2Rvd24gZmlsZXMhhwAOAwlwYXJhZ3JhcGgA","AAJHAQK15YMNAKgADAF3C2gtZG9jdW1lbnRzqAANAXckNWM0NWI4MjEtYTc1MC00OGIyLWEzZjAtMzI3M2M1MmJhYTI1AQABDAI="] 2147483647
Some other information, maybe there's something relevant:
- I see that duplicate behaviour in our test instance, too
- In both instances I have the Versions app enabled
- It seems the problem can be easily reproduced (above example was from a random user, and seen with both Readme.mds we tried).
- Like said in my previous comment I already tried several occ commands to cleanup. I also enabled the Plain Text Editor once and tried to configure it for other filetypes, something like that: https://help.nextcloud.com/t/plain-text-editor-for-all-files/133291 Unfortunately I have not documented it well. Currently the Plain Text Editor is disabled
I have not yet issued any occ text:reset [file-id] commands.
Please let me know if you need anymore info.
- It seems the problem can be easily reproduced
Could you try to reproduce this problem from scratch - i.e. creating a new file or uploading one and then creating the problem from there?
I suspect this is due to editing sessions still being around from before the update. However if you can still create the problem with a new file that could not be the case.
If you can reproduce with new files... could you create a screen recording of the steps so i can try and reproduce myself?
Thanks a lot for your support in tracking this down.
I could not reproduce the problem with a new file with my account and another user's account.
Probably I can reproduce the problem with other users with existing files. Can I check the session state and their files before logging in and reproducing the issues?
- [ ] add an occ task to clean up all sessions
- [ ] repair step that does this with next release
- [ ] ~~store document state after initialization~~ maybe only send content when initializing a doc without any steps rather than without document state :thought_balloon:
In addition maybe we could actually add a timestamp or version identifier to the steps table so we could identify old versions in the future more easily.
Related bugreport in Collectives: https://github.com/nextcloud/collectives/issues/1270