Preview Out-Of-Date if Save is In Progress

[mchowning]

Expected behavior

A post preview should always represent the current content in the editor.

Actual behavior

If an autosave is in progress when the user attempts to preview the post, the currently-being-saved changes will not be uploaded and included in the preview.

Steps to reproduce the behavior

1. Open a very long post, ideally on a slow device (so it will be slow to save)
2. Add some content,
3. Wait at least 0.5 seconds (so the autosave delay has passed), but not much more than that (because we don't want the save to finish) and tap the "Preview" menu button.
4. Observe that the post is not uploaded (assuming there was no other updated content saved apart from what was added just before the preview was opened) and the preview does not include the just-added content.

Tested on Pixel 1, Android 11, WPAndroid 125b398

[mchowning]

When investigating this, we should keep in mind that there is another bug that sometimes causes the preview to not actually open: #12570.

[hypest]

Added the "Priority High" lavel since this essentially means the Preview flow is broken since one cannot preview the changes currently in the editor. Please dive in @mchowning , thanks!

[malinajirka]

I looked into this issue. I added bunch of logs and I think the bug might be in Gutenberg.

When the bug happens, the editor doesn't emit change

mEditorFragment.getTitleOrContentChanged()

Moreover, this method keeps returning the state before the last change (even 5 seconds after the change) -> so even if the EditPostActivity manually tries to sync the content with the UI, it doesn't help, because the EditorFragment keeps returning the old content.

Here are logs when the preview works as expected: (I changed title from "A" to "ABC")

14:22:22.675 - D/WordPress-MAIN: malinjir: change in editor detected.
14:22:38.308 - D/WordPress-MAIN: malinjir: updating from editor: ABC
14:22:38.320 - D/WordPress-MAIN: malinjir: Right before the post is saved into db: ABC
14:22:40.716 - D/WordPress-MAIN: malinjir: updating from editor: ABC
14:22:40.727 - D/WordPress-MAIN: malinjir: Right before the post is saved into db: ABC
14:22:40.754 - D/WordPress-MAIN: malinjir: unpacking post intent: ABC
14:22:40.777 - D/WordPress-MAIN: malinjir: upload handler: ABC
14:22:47.885 - D/WordPress-MAIN: malinjir: postuploaded: ABC
14:22:47.886 - D/WordPress-MAIN: malinjir: postuploaded - repo: ABC

Here are logs when the bug happens: (I changed title from "ABC" to "ABC DEF").

14:24:38.106 D/WordPress-MAIN: malinjir: updating from editor: ABC
14:24:43.829 D/WordPress-MAIN: malinjir: updating from editor: ABC
14:24:43.839 D/WordPress-MAIN: malinjir: Right before the post is saved into db: ABC
14:24:43.867 D/WordPress-MAIN: malinjir: unpacking post intent: ABC
14:24:43.888 D/WordPress-MAIN: malinjir: upload handler: ABC
14:24:49.344 D/WordPress-MAIN: malinjir: postuploaded: ABC
14:24:49.345 D/WordPress-MAIN: malinjir: postuploaded - repo: ABC

I created a testing branch (issue/13361-logs) which is based on this PR and it just adds these testing logs.

[mchowning]

Removed my assignment because I'm not going to have time to get back to this in the near future. Once the new year starts, I will try to find someone else to continue working on this.

[designsimply]

I don't know if this work is small enough to be worked on during a maintenance rotation, but I have added it to the Groundskeeping Prioritized Android list just in case.

[mchowning]

Possibly related to wordpress-mobile/gutenberg-mobile#2207

[cameronvoell]

I looked into this issue. I added bunch of logs and I think the bug might be in Gutenberg.

When the bug happens, the editor doesn't emit change

mEditorFragment.getTitleOrContentChanged()
...
I created a testing branch (issue/13361-logs) which is based on this PR and it just adds these testing logs.

@malinajirka Unfortuntately, I have failed at getting the app in this state that you describe in your comment so far. I checked out your branch so I could see where you're logging, but on title updates I was only getting correct updates, though I tried extensively the steps from this issue description.

The steps in the Issue description say to open a large post on a slow device, I'm wondering if there was some race condition I wasn't achieving using my available devices or on the emulator.

Are there are extra steps that you could advise that could be helpful for getting the app in the state you described, with title updates not being sent from Gutenberg to WPAndroid correctly?

[malinajirka]

Hi @cameronvoell! I tried to build issue/13361-logs and the issue still sometimes happens to me - eg. emulator api 30 and this post.

1. Open a long post
2. Edit the title
3. Wait +-1s
4. Open Preview
5. Check logs and notice updating from editor: [TITLE] sometime contain the out-dated title (if you see the up-to-date title, repeat steps 2-5)

P.S. We can jump on a pair programming session if you want. Let me know.

[cameronvoell]

Hi @cameronvoell! I tried to build issue/13361-logs and the issue still sometimes happens to me - eg. emulator api 30 and this post.

...

P.S. We can jump on a pair programming session if you want. Let me know.

Thanks @malinajirka, those steps with your longer article worked for reproducing the issue near my end of my day today. will dig in more on the Gutenberg side to look for root cause there. Thanks for your help!

[renanferrari]

Hey @cameronvoell 👋 I'm currently on my groundskeeping rotation and I'm wondering if any progress was made on this issue since your last comment or if we're still not sure what the root cause is.

[cameronvoell]

Hi @renanferrari, I was able to find an arguably worse version of this issue that likely has the same underlying cause as this issue: wordpress-mobile/gutenberg-mobile#3177.

It can only be re-created with very large posts, so investigating it likely will involve debugging the autosave handoff between Aztec, Gutenberg, and WPAndroid that should ideally be made immune to performance constraints.

[AmandaRiu]

I tested the following scenarios on a Pixel 4 running Android 11:

• Created a new post using the Gutenberg demo app initial html on the web and then pulled it down to the device. I inserted a new paragraph block to the beginning of the post, added some text, and then clicked preview. The preview was updated with the new text. I tried different timings to see if I could somehow not have the update show up in preview but was not able to replicate the issue.
• I created another really long post using the same text from the test post listed above and then opened it on mobile and edited the title. Waited a second and clicked to preview. change not reflected. Tried again waiting up to 5 seconds (at one point even the "saving" dialog was shown before generating the preview) -- still the title was not updated.

[mkevins]

Following up after #15509, I tested this issue again using the long post content (in the hopes that this may have been resolved via that and the related PRs). Unfortunately, I still encountered the issue (on version 18.6).

[zwarm]

I re-tested on 19.1 using Pixel 5, Android 12:

• Created a long post using the same post as above and published.
• Edited the post - updated the title and added some new paragraph blocks, clicked preview
• Although the saving dialog was shown, followed by generating preview dialog, the title and content were not updated.

[mkevins]

I have confirmed that this issue is still present (tested on Pixel 3a, Android 12, 86225c2). I created a large post using this example content from this comment, and encountered the issue when modifying the content (or title) and selecting the "Preview" from the menu.

I began debugging this issue, and found that there is a very long delay when retrieving the HTML content from the Gutenberg editor (even when there are no changes). In some cases, I seemed to be stuck indefinitely with the "Saving..." dialog presented (I waited greater than 10 minutes on some occasions, and had to kill the app to resume testing 😅 ).

I suspect (but was unable to confirm, due to the difficulty and time-consuming nature of debugging such a large post) that when updatePostObjectWithUIAsync is invoked, and in turn getUpdatedTitleAndContent, the getTitleAndContent from the bridge times out before the getHtmlFromJS completes. I observed in all cases where I encountered the issue that the following error was logged:

"Timeout reached before response from requestGetHtml."

When this issue was first reported and investigated, this error was not being reported properly, even when a timeout was occurring (since the await method does not throw an exception in that case, but rather, merely returns false). These changes (from #36072) make this more visible in this issue as a potential culprit.

I also tried increasing the timeout (to 100s instead of 10, though that may not be a good idea in production), but I would always get stuck with the "Saving..." dialog mentioned earlier.

[mkevins]

I observed in all cases where I encountered the issue that the following error was logged:

Update: I have found steps to reliably reproduce stale previews with even "small" content (i.e. without the save mechanism timing out).

Steps

The following was reproduced on a Pixel 3a (physical device) with Android 12.

1. Go to the drafts tab of the post list and tap the (+) fab to create a new post
2. Type the title "Test"
3. Tap the "Start writing..." placeholder and type a paragraph with the word "Test"
4. Open the preview (tap the three dots menu --> tap "Preview")
5. Observe the preview (containing the content "Test")
6. Tap the back button
7. Tap at the end of the paragraph block and type " test" (the paragraph should now include the content: "Test test")
8. Open the preview
9. Observe the preview (containing the content "Test test")
10. Tap the back button
11. Tap at the end of the paragraph block and type " test" (the paragraph should now include the content: "Test test test")
12. Open the preview
13. 💥 Observe the preview (containing the content "Test test" instead of the expected "Test test test")

It seems that subsequent previews still contain the same stale content. Also, even leaving the post and selecting "View" from the post list displays the stale content. At least for this particular flow, this seems to indicate that this is some kind of a caching issue, and not a race condition within the editor.

Video:

stale-previews.mp4

[malinajirka]

Thanks for looking into this tricky issue! 🙇 Great findings!

Also, even leaving the post and selecting "View" from the post list displays the stale content. At least for this particular flow, this seems to indicate that this is some kind of a caching issue, and not a race condition within the editor.

@mkevins I assume you didn't publish/update the changes, right? So if you can see "View" action on the post card in the list, and not "Publish" action, that'd suggest the app doesn't even know about the changes. Can you see the modified content ("test test test") when you re-open the post in the editor? From what I can tell it seems the issue still might be that the editor doesn't return up-to-date content when the app asks for it (using .getContent()) -> that's what I found during the last investigation of this issue here. Wdyt?

Could you please elaborate a bit why you think this might be a caching issue rather than a race condition?

[mkevins]

Could you please elaborate a bit why you think this might be a caching issue rather than a race condition?

Hi @malinajirka 👋 😄

Good questions! I'm actually in the process of writing up more details about what I've discovered so far, but it will take me some time to get it all written out. I'm pretty certain it's an issue with caching, and indeed the modified content is still present in the editor (but not the preview's webview). What is interesting is that viewing the same preview url via a desktop browser displays the up-to-date version of the content. I'll post more details soon on what else I've discovered.

[mkevins]

Also, I still believe there are also potential race conditions, so this could be a symptom with multiple possible causes. 🤷‍♂️

[ravishanker]

@mkevins made a detailed analysis on this issue in this internal P2 post: pbArwn-3XS-p2