Broken sync

[zefhemel]

From chat, to be investigated:

Matouš Jan Fialka
8:07 pm
Hi. I ran into some serious troubles, see console output after I opened my another SB instance after few weeks… log. I tried: 1. reload several times, 2. reset client, reload several times, completely clear browser data, reload several times, still the same. I can see raw content of any page "blink" for a second and then I get empty or default page (index, SETTINGS, etc.) Can somebody help me with this, please?

Most suspisious are the messages about content not changed etc. If there are no data (closed all tabs, clear page data, ran in private window, etc.) how is that possible? And the weirdest thing is I can see the real content "blink" for a small amount of time and then either empty page is displayed or default page.

I am running one instance on "server" (should be the source of truth), one on my mobile phone (that is OK AFAIK, I hope, at least looks good), and the third one on this computer. Firefox is updated, etc.

(edited)
OK, I restarted the browser, no change, it is still happenning. There is only single tab opened with SB.

Matouš Jan Fialka
8:24 pm
Hm, there are also some conflicts too. At the beginning, when I erase everything possible from the browser and go to the SB URL, I see default index, I see it's syncing (the circular progress appears showing the percents) but that's all. Then it ends up in exactly the state as described above.

I also tried to force reindex, with no success at all. Interesting is that the TreeView plug shows itself, if invoked, but it does not show anything, it's empty. I have no idea how to debug it more, sorry. Just to add, running on Edge build on the "server" instance, @zef would know, we were solving something about Lua today.

(edited)
BTW, it's not the first time I ran into some weird issues with SB on upgrades etc. But this time it's quite bad, I must say, because in the cases before, I just, closed tab, reloaded few times, reset client etc., and it started to work again. This is, sadly, not the case. 😢

Idea: some race between the 3 clients?

Matouš Jan Fialka
8:41 pm
H, now I ran update of plugs on my mobile instance and lost it too. The same behaviour. So it may be something with core plugs not updated properly? I have no idea how to debug it on mobile Firefox at all (I do not run dev version, perhaps I should have)… 😭

Zef Hemel
8:42 pm
Ok this is very confusing. You're running in sync mode? Does this happen if you're not in sync mode?

And not have 3 clients at the same time?

You can probably try deleting all files under _plug/ on your server, reload and see if that changes something

Then if you're in a stable state, run Plugs: Update again

Matouš Jan Fialka
9:01 pm
@zef, give me a second, I think I got it.

@zef Yeah! One plug was empty .js file in the _plugs/ dir. Why? Dunno. I downloaded it manually via raw url from GH and now it seems the content continues to sync. BTW, everytime I add a plug, I need to download it manualy first to the _plugs/ dir. The Plugs: Update command does not yield any error. Also, I had bad times to see from the SB logs what's happenning, because the message "some page was requested" without any instance identification is really not helpful. 😃

Maybe, once new instance is deployed, it should be given unique identity to be later seen in the logs (and from it, of course, via some command or message).

@zef This is not good. All 3 instances, hopefully, run OK now, but the index file is rewritten with the default one and there is a conflict file with my original one (I use another file as index via SETTINGS).

Matouš Jan Fialka
9:16 pm
I think this case shows some rather big issues in (1) how syncing works, (2) that the primary instance (aka server) should be always source of truth until everything is really synced properly (I know that's very hard to achieve), (3) no file was touched by me from any instance, especially not the index file, and it got changed (may it happen to other file as well?) To explain why I run in sync mode (which is annoying if I lose my VPN to the server) - I had to, because there were even more serious issues when not running in the sync mode (corrupted page contents, I edited some page and ended up in a mess several times - maybe it's fixed but I haven't yet managed to even try again). (4) If something fails, such as that some plug could not be downloaded, I should know about it and notified, the sync on the instance should be rollbacked or something, dunno. I know very well these things are very hard and also understand why you would like to have only one mode. Let's do it, if it will be "bulletproof" afterwards. SilverBullet is marvelous, excellent piece of software, but these petite distractions can rise to huge outages (as I saw today). Is there anything we can do, together, about it? There are many experienced hackers here, perhaps they can review some core parts and identify the major flaws? Such a beautiful and extremely useful software as SilverBullet, with all the great ideas of yours, deserves perfect core functioning. (Sorry for the speach, I lost lot of time debugging the issue today, thank you for otherwise excellent software, I am great fan of SB, trust me).

Matouš Jan Fialka
9:25 pm
@zef If I could reproduce for example the (3), I would had filled and issue, but those things happened to me without any logic. But I've seen there are some issues on GH pending that sound quite familiar to those of mine.

Matouš Jan Fialka
9:33 pm
@zef I've just realized that SETTINGS.md on the server was overwritten with the default one as well and there was also a conflicting file with the original content, although both the two other instances are clearly still seeing the correct one (why???). I've corrected it manually on the server side and I hope it will not appear again.

Matouš Jan Fialka
9:40 pm
OK, it was the mobile instance that was thinking it has truth now. To fix it again I had to: (1) change SETTING.md on another instance (typed something in it), then it got synced and also the mobile got it right then. (2) Then I had to reload on index several times and now, as I hope, I have all 3 versions in sync again and can continue to use the great SB from 3 different places at once. 🥰

9:41
I have no real insight why all of this was happenning, it was real mess to me, but perhaps this lengthy report can help to improve things.

[zefhemel]

Things to investigate:

• what happens if a plug file is empty, or somehow invalid?
• In what scenarios are SETTINGS and index pages regenerated, and is this safe?

[mjf]

@zefhemel It also happenned to me several times (before I started to use sync only mode) that when I was editting space-style, I ended up with garbage in it when I navigated somewhere else from it and back. There were new edits misplaced, e.g. I was adding some styling to the end of the space style and when I navigated away from it, the CSS was garbaged, when I navigated back I realized that the new edits were misplaced and placed somewhere in the middle of the space style on a random place. This happenned several times.

I am not 100% sure but I think it happenned to me on some normal Markdown pages too few times.

After I switched to the sync-only mode, these particular things seem to stopped happenning but I started, from time to time, detecting other issues with syncing, e.g., I open Firefox on mobile, go to the SB tab and the content start syncing showing the indicator. When synced (100% shown but who knows), I have to reload several times to get correct content.

It really seems there is some issue with synchronization in the SilverBullet core. I think there is some issue from the very beginning of using SB, not only since the time I use edge builds! I will try to find something less vague and more reproducible.

Also, @zefhemel, it would be good to re-thing the flash notifications. I mean, if I am for example updating the plugs, is the Done notification flashed really after everything is updated, reloaded etc.? Can ve rely on these notifications? I always wait until I see the Done notification before I do anything else in SB but I did not wait before. There is, AFAIK, no document on whether these actions are asynchronous or not. Some general description on how SB behave will be splendid, especially describing the syncing algorithm(s). I feel like I might have been interrupting something from time to time by, e.g., reloading a page before something got properly synced I though was synced. This is just a feeling, I must emphasize, but a good one, I think. Perhaps you could imagine what can be happenning inside the SB that the data end up corrupted, empty or unsynchronized...

[mjf]

@zefhemel Perhaps we should ask the community to describe their syncing issues behaviour here as well? Perhaps we can then spot some union pointing to something more particular...

[mjf]

Weird errors... detecting conflicts where there cannot be any (the so-called "secondary" was intact the time, just opened somewhere in a browser tab, nothing else, nobody touching...) and more to see in the log below too...

It's happenning all the time.

07:44:40.507 Saving page Obsah 3 client.ts:676:20
07:44:46.816 Sync without activity for too long, resetting sync_service.ts:125:14
07:44:46.816 Syncing file Obsah.md sync_service.ts:267:12
07:44:46.822 Sync without activity for too long, resetting sync_service.ts:125:14
07:44:47.010 This should not happen, savingTimeout was not set sync_service.ts:95:16
07:44:47.010 File Obsah.md already scheduled for sync sync_service.ts:198:14
07:44:47.505 Already syncing, aborting individual file sync for Obsah.md sync_service.ts:264:14
07:44:55.195 Syncing file Obsah.md sync_service.ts:267:12
07:44:58.738 This should not happen, savingTimeout was not set sync_service.ts:95:16
07:44:58.739 File Obsah.md already scheduled for sync sync_service.ts:198:14
07:45:06.307 Full sync completed client.ts:298:16
07:45:07.511 Sync without activity for too long, resetting 2 sync_service.ts:125:14
07:45:07.539 Syncing file Obsah.md 2 sync_service.ts:267:12
07:45:07.851 [sync] Performing a full sync cycle... sync.ts:50:12
07:45:07.852 alreadyFetching is on, skipping even triggering for fetchFileList. evented_space_primitives.ts:56:14
07:45:07.860
XHRGET
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 1ms]

07:45:07.870 [sync] File changed on primary, copying to secondary Obsah.md sync.ts:220:14
07:45:07.883
XHRPUT
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 3ms]

07:45:08.508
XHRGET
http://silverbullet.local:12345/index.json
[HTTP/1.1 200 OK 1ms]

07:45:08.521 [sync] New file created on primary, copying to secondary Obsah.conflicted.1740033850287.md sync.ts:134:14
07:45:08.529
XHRPUT
http://silverbullet.local:12345/Obsah.conflicted.1740033850287.md
[HTTP/1.1 200 OK 1ms]

07:45:08.537 [sync] File changed on both ends, potential conflict Obsah.md sync.ts:275:14
07:45:08.537 [sync] Starting conflict resolution for Obsah.md sync.ts:299:12
07:45:08.546
XHRGET
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 1ms]

07:45:08.561 [sync] Files are the same, no conflict sync.ts:322:16
07:45:08.562 [sync] Sync complete, operations performed 1 sync.ts:112:12
07:45:09.803 This should not happen, savingTimeout was not set sync_service.ts:95:16
07:45:09.804 File Obsah.md already scheduled for sync sync_service.ts:198:14
07:45:14.150 Already syncing, aborting individual file sync for Obsah.md sync_service.ts:264:14
07:45:14.165 Current space index version 6 space_index.ts:14:10
07:45:18.531
XHRGET
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 1ms]

07:45:18.538 [sync] File changed on both ends, potential conflict Obsah.md sync.ts:275:14
07:45:18.538 [sync] Starting conflict resolution for Obsah.md sync.ts:299:12
07:45:18.545
XHRGET
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 2ms]

07:45:18.557 [sync] Files are the same, no conflict sync.ts:322:16
07:45:20.020 Already syncing, aborting individual file sync for Obsah.md 2 sync_service.ts:264:14
07:45:20.419 This should not happen, savingTimeout was not set sync_service.ts:95:16
07:45:20.419 File Obsah.md already scheduled for sync sync_service.ts:198:14
07:45:23.649 Aborting space sync: already syncing sync_service.ts:232:14
07:45:23.661
XHRGET
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 3ms]

07:45:23.662
XHRGET
http://silverbullet.local:12345/Obsah.md
[HTTP/1.1 200 OK 1ms]

07:45:30.798 Already syncing, aborting individual file sync for Obsah.md sync_service.ts:264:14
07:45:30.798 Aborting space sync: already syncing sync_service.ts:232:14
07:45:31.277 This should not happen, savingTimeout was not set sync_service.ts:95:16
07:45:31.277 File Obsah.md already scheduled for sync sync_service.ts:198:14
07:45:34.954 Already syncing, aborting individual file sync for Obsah.md sync_service.ts:264:14
07:45:37.050 Syncing file Obsah.md

I think the browsers can not catch up because particularly this page ('Ohsah.md' is my root index page) contains quite lot of generated stuff by either space script or by space Lua. There are also additional hooks at the top and bottom etc. I also cannot get full 100% sync on all clients. One client is showing some value of page count (realized by space script custom function count over a query with conditions to exclude meta and other pages) and another is showing different value (usually +/- 1 or so, could be the conflicted pages, who knows...).

All clients were reseted completely recently after server update to the latest edge (sync only mode).

This indeed looks like some serious race, @zefhemel .

I also inspected the conflicted files and those were just chunks of crap (partially saved page in the middle of editing e.g. code block in the page).

And I still lack a way to identify the nodes. I have no idea which client is the "secondary" here... Please log at least IP addresses or something because even dumping network traffic can't help us much...

Btw: the silverbullet.local does not run on HTTPS as you can see and also does not run on localhost IP address. Does it matter anyhow?

[MrMugame]

Not running over HTTPS is definitely not good. I'm pretty sure http://silverbullet.local wouldn't be considered a secure context. I'm not a 100% how or even if this would exactly cause the issues you mentioned, but the service worker, which caches files in the background wouldn't be running, same is true for plugs.

Is the log above unedited? It seems weird to me. About every ten seconds there must be a editor:pageSaved event emitted judging from the warning This should not happen, savingTimeout was not set. This could e.g. be emitted because saving took longer than 5 seconds, which it in the first case did. 07:44:40.507 vs 07:44:47.010. This is weird why is saving taking 5s? Writing to indexedDB should be fairly quick. Second thing: The later editor:pageSaved events seem to be emitted without a save even starting (i.e. Saving page ...), which is very weird? This could be caused if a plug or space-script just randomly emits events. This would also explain why the savingTimeout isn't set (It would also explain why saving took longer than 5s: It simply didn't, it was an unrelated event). What plugs, scripts, etc are you specifically using? Your instance also seems to be constantly syncing for which I don't have any explanation.

I dont't know to much about silverbullets sync-mode, but those are my thoughts on this. It's pretty much impossible to debug without having a minimal example on which this happens. This also makes it very probable that this is not necessarily ann issue with silverbullets core, but rather with some plug, script, your setup, file, etc. Silverbullet is very hackable by design, which also makes it very breakable.

[zefhemel]

I have to look at this in detail, but just to clarify what primary and secondary mean: primary always refers to the local in-browser copy (stored in IndexedDB), and secondary refers to the server version.

[mjf]

@zefhemel I think a way to distinquish between secondary instances is highly needed for better debugging on the primary.

[zefhemel]

Distinguish where?

[Noggog]

To pitch in in case it's applicable, I got to this issue because I've been dealing with content randomly getting deleted as I type, with the message "modified elsewhere" popping up. I can recover by hitting undo which brings my deleted content back and then I can continue typing, but it's a bit disturbing to deal with

[Noggog]

This is definitely becoming an issue. Many times I'll go to my silverbullet page, type some content in, close it, and then come back and see it didn't commit my changes. I've gotten in the habit of religiously pressing the Sync: Now command (annoying to do on the phone, as there's no keybind, ofc). Even then, i'm always paranoid some content will be lost.

[florent4014]

I 'm also experiencing the same issue, one big page of content just disapeared half a second before closing the tab, lost few hours of writing. Nothing in logs, the md file is empty. I never use sync mode, always online mode.

EDIT: It seems that there is another piece of software on my server that was randomly filling the disk space to 100% for few minutes. This caused silverbullet to empty the current .md file i was editing. Be careful to disk space when using SB