Opening multiple tabs may prevent proper syncing of channel changes

[bjester]

Observed behavior

There have been multiple issue reports that intersect with the syncing of changes from the frontend to the backend:

• changes disappear after some time
• copy or publishing tasks never complete or show any progress
• inability to publish after making changes

From the insight we've been able to gather, it seems to involve having Studio open in multiple tabs, similar to #3906. Although, we've received few error reports in Sentry coinciding with these user reports. Some areas for investigation:

• could Chrome's new memory saver feature be the culprit, pausing the tabs that are elected leader for syncing changes
• could it be related to DatabaseClosedErrors that we've received a couple times (DatabaseClosedError: DatabaseClosedError Database has been closed #3945)

Expected behavior

• Content or changes do not disappear
• Copy or publishing tasks show some progress soon after initiating
• Changes are appropriately synced, allowing the channel to be then Published

User-facing consequences

• Lost time and energy that was put into content that disappears
• Confusion on why Studio isn't showing any activity

Additional information

https://community.learningequality.org/t/kolibri-studio-not-saving-and-publishing/2745
https://learningequality.slack.com/archives/C0LK8QS9J/p1677873471445029
https://learningequality.slack.com/archives/C0LK8QS9J/p1675989425072409
https://learningequality.slack.com/archives/C0LK8QS9J/p1678811138967969

Usage Details

• OS: mixed
• Browser: Chrome (at least)

[bjester]

@pcenov (cc @radinamatic) could you try to reproduce this? we have limited information, but multiple reports

[pcenov]

@bjester I was able to replicate twice a failure to sync the channel changes by doing the following:

1. Open Studio in several tabs in Chrome
2. In one of the tabs throttle the network connection to Slow 3G and start editing folders and resources.
3. Open Studio with the same account in Firefox and keep monitoring the syncing of the changes made in Chrome
4. At some point some resources in Firefox get marked as incomplete and refreshing the page or exiting and entering again the channel editor doesn't result in syncing the changes.

Video:

Short.mp4

Screenshot:

I couldn't spot any relevant errors besides this one at some point:

XHRPOSThttps://studio.learningequality.org/api/sync/
[HTTP/3 502 Bad Gateway 206ms]

There was an error updating change status:  TypeError: node is undefined
    tableCopy https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    applyCopy https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    transaction https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    c https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    follow https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    ot https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Je https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    follow https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Ie https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Ce https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    follow https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Pn https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    ut https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Fe https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Ue https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    qe https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    promise callback*ve< https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    ge https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Re https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    o https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Ie https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Ce https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    n https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Pn https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    _whenReady https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    _transaction https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    transaction https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    transaction https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    applyCopy https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    resolveTreeInsert https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    promise callback*resolveTreeInsert/</< https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    promise callback*lock https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    treeLock https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    resolveTreeInsert https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    ut https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Fe https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    Ue https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    We https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    create https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    dt https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    _trans https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    get https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    get https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    resolveParent https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    resolveTreeInsert https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    applyCopy https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    applyChanges https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    handleReturnedChanges https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    debouncedSyncChanges https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    debouncedSyncChanges https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    invokeFunc https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    trailingEdge https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    timerExpired https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    sentryWrapped https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    setTimeout handler*_wrapTimeFunction/< https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    leadingEdge https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    debounced https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    sentryWrapped https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    setInterval handler*_wrapTimeFunction/< https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    startSyncing https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    promise callback*runElection https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    <anonymous> https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    async* https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    async* https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    <anonymous> https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
    <anonymous> https://studio.learningequality.org/static/studio/channel_edit-cac3b745ca6475b6b22f.js:7
channel_edit-cac3b745ca6475b6b22f.js:7:4423846

My guess is that the combination of having multiple tabs open in combination with slow internet connection is causing the issues. See if you can replicate and let me know if you need any additional info.

[rtibbles]

I have done specific testing to see if this might be related to the Chrome Energy Saver, and it seems not to be. Activating the energy saver unload for a tab correctly switches syncing to a different tab.

[bjester]

The energy saver is the same as the memory saver?

[rtibbles]

Oh sorry - I tested both, but I did mean memory saver here.

[bjester]

Shoot. Well I guess @pcenov's reproduction might have clues? I missed his comment here

[rtibbles]

Yeah, on first glance it looks like the error is happening if getting the node for resolving a tree insert fails.

[rtibbles]

I suspect that this is actually still being caused by a combination of the hidden tab being elected the leader, and Chrome's timer throttling: https://developer.chrome.com/blog/timer-throttling-in-chrome-88/

I noticed this while doing some testing, that the hidden tab did get its timer throttled for a long period of time, while in the other tab I was doing a large amount of editing and uploading.

This was noticeable, because I had edited the sync to run from both tabs, and was also forwarding the sync request within a service worker. This meant that in the hidden tab's network tab, I was able to see a long sequence of sync requests forwarded by the service worker, that had come from the active tab, while the hidden tab had not sent any sync requests in that time.

[rtibbles]

I am beginning to suspect that Dexie Observable may be susceptible to these issues as well, as it uses timers as a fallback for checking for changes, so we may be getting a double whammy of timer issues, both in responding to Dexie Observable changes and writing to our own changes table, and also in then carrying out the sync to the backend.

I think it may be worth while to start the migration away from Dexie Observable, by explicitly writing to our changes table for CREATE, UPDATE, and DELETE in the same way that we do for MOVE, COPY, PUBLISH, etc.

The advantage of this approach is that we don't have to worry about multiple writes to our changes table, as we'll be doing it directly in the tab where the change is being made - it will mean that we can't flatten changes as aggressively, but I'm not sure that's too much of an issue currently anyway.

That would mean the only thing we are still using Dexie Observable for is the listeners to keep the Vuex state updated - this could then be migrated to using live queries instead, and we could drop Dexie Observable.