Bug: Turbo.visit Render sequence race condition for Cache and Request #447

tleish · 2021-11-16T07:07:04Z

I came across what I believe to be a bug.

Visit page (saves to turbo cache)
Leave page
Return to same turbo-cached page via server 302 redirect
Quick flash of new network request content, but then replaced by old cached version.

Fetch requests show updated content in network request.

A few additional observations:

Render via direct GET request (no redirect) of cached page works as expected
Render via POST|PUT|DELETE and 302 redirect works as expected
Render via GET and 302 redirect DOES NOT work as expected

Adding to the landing page page temporarily resolves the issue, but unless I'm misunderstanding turbo caching, adding to every page with a redirect is not permanent solution.

Small demo app to reproduce the error:
GitHub - tleish/turbo-cache-test

Turbo 7.0.1 and v7.1.0-rc.1
Rails 6.1.4.1
Chrome Latest
Firefox Latest
Safari Latests

Bug also reported in this MR (#445 (comment))

tleish · 2021-11-16T15:34:35Z

FYI, after additional troubleshooting I found the following sequence of events:

Events after POST, PUT, DELETE 302 Redirect

proposeVisit
- visitProposedToLocation
  - turbo:before-render
  - turbo:render
  - turbo:load

Events after GET 302 Redirect

proposeVisit
- visitProposedToLocation
  - turbo:before-render
  - turbo:render
  - turbo:load
followRedirect
- visitProposedToLocation
  - turbo:before-render
  - turbo:render

If I disable #followRedirect, then POST, PUT, DELETE and GET render work as expected, however the URL is not updated with the redirected URL.

complete() {
  if (this.state == VisitState.started) {
    this.recordTimingMetric(TimingMetric.visitEnd)
    this.state = VisitState.completed
    this.adapter.visitCompleted(this)
    this.delegate.visitCompleted(this)
-   this.followRedirect()
  }
}

Related to #328. Maybe @jaysson can take a look?

FYI, this may be also related to #428

tleish · 2021-11-17T16:46:06Z

We are bumping into this issue multiple places in our Rails application. So, we come up with an ugly workaround to force Turbo to reload the page when a redirect after GET.

Intercepts the redirect_to method and if it's a GET request, it stores a temporary flash variable
Then, the overall template reads the flash variable and if true renders an empty style which forces turbo to reload the page.

# application_controller.rb
class ApplicationController < ActionController::Base

+ private
+  
+ def redirect_to(*)
+   session[:redirect_from_get] = request.request_id if request.get?
+  super
+ end
end

<!-- application.html.erb -->
<!DOCTYPE html>
<html>
  <head>
    <title>My Title</title>
    <meta name="viewport" content="width=device-width,initial-scale=1">
    <%= csrf_meta_tags %>
    <%= csp_meta_tag %>

    <%= stylesheet_link_tag 'application', media: 'all', 'data-turbolinks-track': 'reload' %>
    <%= javascript_pack_tag 'application', 'data-turbolinks-track': 'reload' %>

+  <%= %(<style data-turbo-track="reload" data-turbo-cache-key="#{session.delete(:redirect_from_get)}"></style>) if session[:redirect_from_get] %>
  </head>

  <body>
    <%= yield %>
  </body>
</html>

Note: this workaround causes additional requests:

Normally you'd see

fetch request (302)
fetch redirect request (200)

With workaround you see:

fetch request (302)
fetch redirect request (200)
GET request (302)
GET redirect request (200)

jaysson · 2021-11-17T17:38:24Z

My PR relied on a then valid behaviour where visitToProposedLocation accepts response option, and uses that instead of the cached HTML. It seems that isn't happening currently.

Ref:

turbo/src/core/drive/visit.ts

Line 272 in 6b6bdb2

response: this.response

tleish · 2021-11-18T17:39:35Z

I've narrowed down this bug to a race condition BrowserAdapter#visitStarted, which not only impacts redirect visits to a cached page, but other visits to a cached page as well (including work discussed in #445).

BrowserAdapter#visitStarted Race Condition

The BrowserAdapter has the following:

export class BrowserAdapter implements Adapter {
  //...
  visitStarted(visit) {
    visit.issueRequest() //=> Async send request
    visit.changeHistory()
    visit.goToSamePageAnchor()
    visit.loadCachedSnapshot() //=> render cached snapshot while waiting for async request
  }

Scenario 1: Works as expected

Visit cached page with response from server

Turbo.visit('page1.html'); // renders cache then renders response

Scenario 2: Does not work as expected

Visit cached page with local copy of response

Turbo.visit('page1.html', { response }); // renders response then renders cache

In this scenario, since we already have the response, there's no wait time and #issueRequest renders the response immediately before loadCachedSnapshot renders the cache. This is confirmed by delaying #issueRequest by 1ms:

export class BrowserAdapter implements Adapter {
  //...
  visitStarted(visit) {
-   visit.issueRequest()
+   window.setTimeout(() => visit.issueRequest(), 1)
    visit.changeHistory()
    visit.goToSamePageAnchor()
    visit.loadCachedSnapshot()
  }

Turbo.visit('page1.html', { response }); // renders cache then renders response

I'm not suggesting this as a solution, but the problem goes away with this change.

Solution 1: BrowserAdapter#visitStarted

Change the order of calls in BrowserAdapter#visitStarted.

export class BrowserAdapter implements Adapter {
  //...
  visitStarted(visit: Visit) {
+   visit.loadCachedSnapshot()
    visit.issueRequest()
    visit.changeHistory()
    visit.goToSamePageAnchor()
-   visit.loadCachedSnapshot()
  }

Thoughts:

I'm assuming the original intent was to issue the async request as soon as possible, then do the rest of the work. Moving loadCachedSnapshot might not be the most efficient approach for standard requests
This feels brittle in having a dependency on the function call order.

Solution 2: Visit#loadCachedSnapshot

Check if this.response has already been populated before rendering the cache in Visit#loadCachedSnapshot. This feels cleaner to me.

export class Visit implements FetchRequestDelegate {
  //...
  loadCachedSnapshot() {
    const snapshot = this.getCachedSnapshot()
-   if (snapshot) {
+   if (snapshot && !this.hasPreloadedResponse()) {
      const isPreview = this.shouldIssueRequest()
      this.render(async () => {
        this.cacheSnapshot()
        if (this.isSamePage) {
          this.adapter.visitRendered(this)
        } else {
          if (this.view.renderPromise) await this.view.renderPromise
          await this.view.renderPage(snapshot, isPreview)
          this.adapter.visitRendered(this)
          if (!isPreview) {
            this.complete()
          }
        }
      })
    }
  }

Thoughts:

This more robust and in the off chance that this method is called from somewhere other than BrowserAdapter#visitStarted, we only render if this.response has not already been populated
Is there a chance where this.response is populated, but we still want to render the cache anyway?

Unit Test

I'm having issues running the Turbo tests suite in general. This makes it difficult to create a test to make sure we detect if the cache is rendered before the request. Most of my tests pass, but a handful fail:

TOTAL: tested 2 platforms, 389 passed, 29 failed; fatal error occurred

No unit test coverage for firefox on mac 20.6.0
firefox on mac 20.6.0: 180 passed, 29 failed
(ノಠ益ಠ)ノ彡┻━┻
NoSuchDriver: [DELETE http://localhost:4444/wd/hub/session/945db6db-def3-744e-b6bd-b2c2408f9bc4] Tried to run command without establishing a connection
Build info: version: '3.141.59', revision: 'e82be7d358', time: '2018-11-14T08:25:53'
System info: host: 'tleish.local', ip: 'fe80:0:0:0:46d:6ee1:76bd:eeb%en0', os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '10.16', java.version: '13.0.1'
Driver info: driver.version: unknown
  at Server.delete @ node_modules/src/Server.ts:392:16
  at Server.deleteSession @ node_modules/src/Server.ts:1911:29
  at InitializedProxiedSession.Session.quit @ node_modules/src/Session.ts:1976:24
  @ src/lib/ProxiedSession.ts:79:31

@seanpdoyle - Which of the solutions above do you prefer? Any tips on how to fix my unit tests so I can create a PR? (Unless you want to create the test).

seanpdoyle · 2021-11-18T17:55:29Z

My PR relied on a then valid behaviour where visitToProposedLocation accepts response option, and uses that instead of the cached HTML. It seems that isn't happening currently.

@jayohms could this be related to https://github.com/hotwired/turbo/pull/328/files#diff-78d8451f964182fd51330bac500ba6e71234f81aad9e8a57e682e723d0f517b3?

tleish · 2021-11-18T17:58:52Z

@seanpdoyle - read my last comment and you'll see it's not directly caused by the Turbo redirect code, but rather a Turbo.visit with a response already on hand.

Turbo.visit('page1.html', { response }); // renders response then renders cache

seanpdoyle · 2021-11-18T18:07:37Z

@tleish I tend to run the test suite with one browser at a time by passing the --environment flag with either chrome or firefox. Does that help you get a passing suite?

tleish · 2021-11-18T18:33:38Z

@tleish I tend to run the test suite with one browser at a time by passing the --environment flag with either chrome or firefox. Does that help you get a passing suite?

@seanpdoyle -- Yes. It looks like some of my firefox tests fail on the latest main branch (something in my environment), but I can at least run all chrome tests locally and once they pass have the CI test both browsers.

Thanks!

tleish · 2021-11-19T01:05:09Z

I am struggling creating a test that mimics the actual caching behavior I'm seeing where the cache is rendered after the preloadedResponse.
Looks like neither of those solutions are viable as either breaks a test.

tleish · 2021-11-19T11:20:06Z

Now able to reproduce it in a test, will create a PR with a failing test today

mildred · 2021-11-22T11:19:04Z

Client-side hotfix based on the above pull request:

// FIXME: Hotfix for <https://github.com/hotwired/turbo/issues/447>
Turbo.session.adapter.__proto__.visitStarted = function(visit) {
  visit.loadCachedSnapshot()
  visit.issueRequest()
  visit.changeHistory()
  visit.goToSamePageAnchor()
}

tleish mentioned this issue Nov 16, 2021

Introduce turbo:frame-missing event #445

Merged

tleish changed the title ~~Bug: Turbo Cache overrides updated version after server redirect~~ Bug: Turbo Cache overrides network request after GET 302 Redirect Nov 16, 2021

tleish changed the title ~~Bug: Turbo Cache overrides network request after GET 302 Redirect~~ Bug: Turbo.visit Render sequence race condition for Cache and Request Nov 18, 2021

tleish mentioned this issue Nov 19, 2021

Do not render cache after preloaded response #458

Merged

dhh closed this as completed in #458 Nov 22, 2021

This was referenced Nov 23, 2021

Form submit not clearing cache #193

Closed

Bug: Cached Preview Rendered After New Content #481

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Bug: Turbo.visit Render sequence race condition for Cache and Request #447

Bug: Turbo.visit Render sequence race condition for Cache and Request #447

tleish commented Nov 16, 2021 •

edited

Loading

tleish commented Nov 16, 2021 •

edited

Loading

tleish commented Nov 17, 2021 •

edited

Loading

jaysson commented Nov 17, 2021 •

edited

Loading

tleish commented Nov 18, 2021 •

edited

Loading

seanpdoyle commented Nov 18, 2021 •

edited

Loading

tleish commented Nov 18, 2021 •

edited

Loading

seanpdoyle commented Nov 18, 2021

tleish commented Nov 18, 2021 •

edited

Loading

tleish commented Nov 19, 2021

tleish commented Nov 19, 2021

mildred commented Nov 22, 2021

Bug: Turbo.visit Render sequence race condition for Cache and Request #447

Bug: Turbo.visit Render sequence race condition for Cache and Request #447

Comments

tleish commented Nov 16, 2021 • edited Loading

tleish commented Nov 16, 2021 • edited Loading

tleish commented Nov 17, 2021 • edited Loading

jaysson commented Nov 17, 2021 • edited Loading

tleish commented Nov 18, 2021 • edited Loading

BrowserAdapter#visitStarted Race Condition

Scenario 1: Works as expected

Scenario 2: Does not work as expected

Solution 1: BrowserAdapter#visitStarted

Solution 2: Visit#loadCachedSnapshot

Unit Test

seanpdoyle commented Nov 18, 2021 • edited Loading

tleish commented Nov 18, 2021 • edited Loading

seanpdoyle commented Nov 18, 2021

tleish commented Nov 18, 2021 • edited Loading

tleish commented Nov 19, 2021

tleish commented Nov 19, 2021

mildred commented Nov 22, 2021

tleish commented Nov 16, 2021 •

edited

Loading

tleish commented Nov 16, 2021 •

edited

Loading

tleish commented Nov 17, 2021 •

edited

Loading

jaysson commented Nov 17, 2021 •

edited

Loading

tleish commented Nov 18, 2021 •

edited

Loading

seanpdoyle commented Nov 18, 2021 •

edited

Loading

tleish commented Nov 18, 2021 •

edited

Loading

tleish commented Nov 18, 2021 •

edited

Loading