Turbo Frame Optimization: Reduced Download Time, but Increased Waiting Time

Hi everyone,

I’m working on optimizing the performance of a Rails application and recently ran into an issue when trying to improve the response times for the following route:

https://.../patients/pat_yb2vmd93E6a6CVQL7WwZg4DR/medical_certificates/new

According to my browser’s network tools, the original request had a 46ms waiting time and a 362ms download time.

Here’s the relevant code for the view and controller:

Original View:

<% content_for :bg_class, "bg-neutral-100 overflow-hidden shadow ring-1 ring-gray-900/5 rounded-lg" %>
<div data-controller="patients-show" class="p-2">
  <%= render partial: 'shared/breadcrumbs', locals: { back_link: patients_path, back_text: 'Voltar', breadcrumbs: [
    { name: t('patients.title'), path: patients_path },
    { name: @patient.name.titleize, path: patient_path(@patient) },
  ] } %>

  <div class="mt-6">

    <%= render 'patients/patient_header' %>
    <%= turbo_frame_tag 'tab_content' do %>

      <div data-content="documents" class="mt-6 flex w-full default-area">
        <div id="container" class="mt-4 flex w-full flex-row">
          <nav class="flex hidden w-auto flex-col lg:block" aria-label="Sidebar">
            <ul role="list" class="space-y-2">
              <li>
                <%= link_to new_patient_medical_certificate_path, class: "h-32 w-32 rounded-lg bg-gray-100 border border-1 border-ow-500 flex items-center justify-center flex-col text-center" do %>
                  <%= inline_svg_tag("medication_notes_icon_highlighted", height: 52, class: "pt-2 h-12 text-ow-600 text-sm") %>
                  <span class="pt-2 text-sm text-ow-600"><%= t('.certificate') %></span>
                <% end %>
              </li>
              <li>
                <%= link_to new_patient_prescription_path, class: "h-32 w-32 rounded-lg border border-gray-200 hover:border-ow-500 hover:bg-gray-50 hover:border-2 flex items-center justify-center flex-col text-center" do %>
                  <%= inline_svg_tag("prescription_icon", height: 52, class: "pt-2 h-12 text-ow-600 text-sm") %>
                  <span class="pt-2 text-sm text-gray-600"><%= t('prescriptions.new.prescriptions') %></span>
                <% end %>
              </li>
            </ul>
          </nav>
          <div id="content" class="flex w-full flex-auto rounded-lg">
            <div class="w-full px-12 py-3">
              <div class="sm:flex sm:items-center sm:justify-between">
                <div>
                  <h3 class="default-h1"><%= t('.certificate') %></h3>
                  <p class="text-gray-500 default-p"><%= t('.certificate_description') %></p>
                </div>
                <div class="mt-5 flex justify-center sm:mt-0">
                  <%= link_to t('.history'), patient_medical_certificates_path(@patient), target: '_top', class: "flex items-center justify-center rounded-md bg-white px-3 py-2 text-sm font-semibold text-gray-900 shadow-sm ring-1 ring-inset ring-gray-300 hover:bg-gray-50" %>
                </div>
              </div>
              <div class="py-8">
                <div class="rounded-lg bg-gray-900/5 shadow ring-1 ring-gray-200">
                  <div class="px-16 pt-8 pb-8">
                    <%= turbo_frame_tag 'certificate_form' do %>
                      <%= render partial: 'form', locals: { patient: @patient, certificate: MedicalCertificate.new } %>
                    <% end %>
                  </div>
                </div>
              </div>
            </div>
          </div>
        </div>
      </div>

    <% end %>
  </div>
</div>

Original Controller:

def new
end

To improve the download time, I made the following changes:

  • Created a partial:
<%= turbo_frame_tag 'tab_content' do %>

  <div data-content="documents" class="mt-6 flex w-full default-area">

    <div id="container" class="mt-4 flex w-full flex-row">

      <nav class="flex hidden w-auto flex-col lg:block" aria-label="Sidebar">
        <ul role="list" class="space-y-2">
          <li>
            <%= link_to new_patient_medical_certificate_path, class: "h-32 w-32 rounded-lg bg-gray-100 border border-1 border-ow-500 flex items-center justify-center flex-col text-center" do %>
              <%= inline_svg_tag("medication_notes_icon_highlighted", height: 52, class: "pt-2 h-12 text-ow-600 text-sm") %>
              <span class="pt-2 text-sm text-ow-600"><%= t('.certificate') %></span>
            <% end %>
          </li>
          <li>
            <%= link_to new_patient_prescription_path, class: "h-32 w-32 rounded-lg border border-gray-200 hover:border-ow-500 hover:bg-gray-50 hover:border-2 flex items-center justify-center flex-col text-center" do %>
              <%= inline_svg_tag("prescription_icon", height: 52, class: "pt-2 h-12 text-ow-600 text-sm") %>
              <span class="pt-2 text-sm text-gray-600"><%= t('prescriptions.new.prescriptions') %></span>
            <% end %>
          </li>
        </ul>
      </nav>

      <div id="content" class="flex w-full flex-auto rounded-lg">
        <div class="w-full px-12 py-3">
          <div class="sm:flex sm:items-center sm:justify-between">
            <div>
              <h3 class="default-h1"><%= t('.certificate') %></h3>
              <p class="text-gray-500 default-p"><%= t('.certificate_description') %></p>
            </div>
            <div class="mt-5 flex justify-center sm:mt-0">
              <%= link_to t('.history'), patient_medical_certificates_path(@patient), target: '_top', class: "flex items-center justify-center rounded-md bg-white px-3 py-2 text-sm font-semibold text-gray-900 shadow-sm ring-1 ring-inset ring-gray-300 hover:bg-gray-50" %>
            </div>
          </div>
          <div class="py-8">
            <div class="rounded-lg bg-gray-900/5 shadow ring-1 ring-gray-200">
              <div class="px-16 pt-8 pb-8">
                <%= turbo_frame_tag 'certificate_form' do %>
                  <%= render partial: 'form', locals: { patient: @patient, certificate: MedicalCertificate.new } %>
                <% end %>
              </div>
            </div>
          </div>
        </div>
      </div>

    </div>
  </div>

<% end %>

  • Updated the View:
<% content_for :bg_class, "bg-neutral-100 overflow-hidden shadow ring-1 ring-gray-900/5 rounded-lg" %>
<div data-controller="patients-show" class="p-2">
  <%= render partial: 'shared/breadcrumbs', locals: { back_link: patients_path, back_text: 'Voltar', breadcrumbs: [
    { name: t('patients.title'), path: patients_path },
    { name: @patient.name.titleize, path: patient_path(@patient) },
  ] } %>

  <div class="mt-6">
    <%= render 'patients/patient_header' %>
    <%= render 'new_content' %>
  </div>

</div>
  • Updated the Controller:
def new
  render partial: "new_content" if turbo_frame_request?
end

After these changes, the download time significantly improved, dropping to around 4ms, but the waiting time increased to around 290ms. I was expecting the waiting time to stay the same, while the download time would decrease.

Did I miss something? Why would the waiting time increase so much after these changes?

Thanks in advance for any insights!

Let me see if I understood correctly: you didn’t change the view code, you just moved part of the view into a partial and respond with just the partial for the turbo request?

How has this affected your server rendering time? I’m not seeing anything that looks like it should be super heavy to render in the rest of the partial so I’d be surprised if that made a big difference to rendering time.

And that 4ms waiting time looks suspiciously low. Even a super fast rails endpoint not doing anything will end up having 1-2ms server rendering time. So for overall waiting time of 4ms, you’d need sub 2ms latency, meaning you’d need to be physically in the same city as the server.

Can you share the network recording and the matching server rails logs? (For network recording, in dev tools you have a download button, in chrome it’s top right, down arrow icon and downloads a HAR file).

Another thing that will help you greatly in diagnosing these kind of issues is to get familiar with rack mini profiler and use it in production: GitHub - MiniProfiler/rack-mini-profiler: Profiler for your development and production Ruby rack apps.

Hi @radanskoric, thanks for your support!

I did’t know MiniProfiler, I’m kind of new in rails - worked mainly with mobile until today. I’ll have a look at it, thanks

I’ve included bellow both the logs and the har

The steps I did:

  • I started with a full page request to: patients/pat_obDap4X7n8GgFy6EgdAkK8Qz/medical_certificates/new
  • Then I clicked another tab progress/new
  • And then went back to medical_certificates/new (receiving only the frame content this time)
  • went back to tab progress/new
  • and back to medical_certificates/new again (this time receiving wait time 277ms)

Logs:

I, [2024-11-21T12:43:15.485873 #145]  INFO -- : [eee9b5b4-4aa1-4233-b650-cd1c881f85ee] Started GET "/patients/pat_obDap4X7n8GgFy6EgdAkK8Qz/medical_certificates/new" for 162.158.79.6 at 2024-11-21 12:43:15 +0000
I, [2024-11-21T12:43:15.491343 #145]  INFO -- : [eee9b5b4-4aa1-4233-b650-cd1c881f85ee] Processing by MedicalCertificatesController#new as HTML
I, [2024-11-21T12:43:15.491383 #145]  INFO -- : [eee9b5b4-4aa1-4233-b650-cd1c881f85ee]   Parameters: {"patient_id"=>"pat_obDap4X7n8GgFy6EgdAkK8Qz"}
I, [2024-11-21T12:43:15.509457 #145]  INFO -- : [eee9b5b4-4aa1-4233-b650-cd1c881f85ee]   Rendered layout layouts/application.html.erb (Duration: 9.0ms | Allocations: 8452)
I, [2024-11-21T12:43:15.509612 #145]  INFO -- : [eee9b5b4-4aa1-4233-b650-cd1c881f85ee] Completed 200 OK in 18ms (Views: 8.7ms | ActiveRecord: 5.0ms | Allocations: 10881)
I, [2024-11-21T12:43:17.291411 #170]  INFO -- : [e501dbaa-9d67-40b5-b2e8-c929aabb04a9] Started GET "/up" for 10.206.17.198 at 2024-11-21 12:43:17 +0000
I, [2024-11-21T12:43:17.291471 #149]  INFO -- : [6daa4f42-f826-4d84-bf29-02c7d02e8ee7] Started GET "/up" for 10.206.17.198 at 2024-11-21 12:43:17 +0000
I, [2024-11-21T12:43:17.296845 #149]  INFO -- : [6daa4f42-f826-4d84-bf29-02c7d02e8ee7] Processing by Rails::HealthController#show as */*
I, [2024-11-21T12:43:17.297072 #170]  INFO -- : [e501dbaa-9d67-40b5-b2e8-c929aabb04a9] Processing by Rails::HealthController#show as */*
I, [2024-11-21T12:43:17.297449 #149]  INFO -- : [6daa4f42-f826-4d84-bf29-02c7d02e8ee7] Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms | Allocations: 186)
I, [2024-11-21T12:43:17.297706 #170]  INFO -- : [e501dbaa-9d67-40b5-b2e8-c929aabb04a9] Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms | Allocations: 186)
I, [2024-11-21T12:43:21.787760 #145]  INFO -- : [0cbbd226-3087-4414-b361-5b0362200fb2] Started GET "/patients/pat_obDap4X7n8GgFy6EgdAkK8Qz/progresses/new" for 172.71.10.238 at 2024-11-21 12:43:21 +0000
I, [2024-11-21T12:43:21.793265 #145]  INFO -- : [0cbbd226-3087-4414-b361-5b0362200fb2] Processing by ProgressesController#new as HTML
I, [2024-11-21T12:43:21.793309 #145]  INFO -- : [0cbbd226-3087-4414-b361-5b0362200fb2]   Parameters: {"patient_id"=>"pat_obDap4X7n8GgFy6EgdAkK8Qz"}
I, [2024-11-21T12:43:21.805916 #145]  INFO -- : [0cbbd226-3087-4414-b361-5b0362200fb2] Completed 200 OK in 13ms (Views: 3.8ms | ActiveRecord: 5.2ms | Allocations: 4631)
I, [2024-11-21T12:43:22.291771 #170]  INFO -- : [0d0e6828-8738-45f3-b388-3e3ad84c4669] Started GET "/up" for 10.206.17.198 at 2024-11-21 12:43:22 +0000
I, [2024-11-21T12:43:22.296769 #170]  INFO -- : [0d0e6828-8738-45f3-b388-3e3ad84c4669] Processing by Rails::HealthController#show as */*
I, [2024-11-21T12:43:22.297305 #170]  INFO -- : [0d0e6828-8738-45f3-b388-3e3ad84c4669] Completed 200 OK in 0ms (Views: 0.2ms | ActiveRecord: 0.0ms | Allocations: 187)
I, [2024-11-21T12:43:23.711725 #181]  INFO -- : [1713f561-fa36-4319-bf04-5f95fb6adb1f] Started GET "/patients/pat_obDap4X7n8GgFy6EgdAkK8Qz/medical_certificates/new" for 162.158.78.194 at 2024-11-21 12:43:23 +0000
I, [2024-11-21T12:43:23.717465 #181]  INFO -- : [1713f561-fa36-4319-bf04-5f95fb6adb1f] Processing by MedicalCertificatesController#new as HTML
I, [2024-11-21T12:43:23.717506 #181]  INFO -- : [1713f561-fa36-4319-bf04-5f95fb6adb1f]   Parameters: {"patient_id"=>"pat_obDap4X7n8GgFy6EgdAkK8Qz"}
I, [2024-11-21T12:43:23.729025 #181]  INFO -- : [1713f561-fa36-4319-bf04-5f95fb6adb1f] Completed 200 OK in 11ms (Views: 3.6ms | ActiveRecord: 3.9ms | Allocations: 5118)
I, [2024-11-21T12:43:27.293807 #170]  INFO -- : [cda73a3c-a447-4a66-b23c-6fcd915576db] Started GET "/up" for 10.206.17.198 at 2024-11-21 12:43:27 +0000
I, [2024-11-21T12:43:27.302344 #170]  INFO -- : [cda73a3c-a447-4a66-b23c-6fcd915576db] Processing by Rails::HealthController#show as */*
I, [2024-11-21T12:43:27.303271 #170]  INFO -- : [cda73a3c-a447-4a66-b23c-6fcd915576db] Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms | Allocations: 186)
I, [2024-11-21T12:43:31.308541 #170]  INFO -- : [1be1bd59-5b72-44b1-ad8a-e25911c7a3da] Started GET "/patients/pat_obDap4X7n8GgFy6EgdAkK8Qz/progresses/new" for 162.158.79.99 at 2024-11-21 12:43:31 +0000
I, [2024-11-21T12:43:31.314558 #170]  INFO -- : [1be1bd59-5b72-44b1-ad8a-e25911c7a3da] Processing by ProgressesController#new as HTML
I, [2024-11-21T12:43:31.314629 #170]  INFO -- : [1be1bd59-5b72-44b1-ad8a-e25911c7a3da]   Parameters: {"patient_id"=>"pat_obDap4X7n8GgFy6EgdAkK8Qz"}
I, [2024-11-21T12:43:31.327867 #170]  INFO -- : [1be1bd59-5b72-44b1-ad8a-e25911c7a3da] Completed 200 OK in 13ms (Views: 3.4ms | ActiveRecord: 5.1ms | Allocations: 4630)
I, [2024-11-21T12:43:32.295729 #145]  INFO -- : [8bbe7626-57cb-4cc2-b3ab-b8dbbe318adf] Started GET "/up" for 10.206.17.198 at 2024-11-21 12:43:32 +0000
I, [2024-11-21T12:43:32.307488 #145]  INFO -- : [8bbe7626-57cb-4cc2-b3ab-b8dbbe318adf] Processing by Rails::HealthController#show as */*
I, [2024-11-21T12:43:32.308366 #145]  INFO -- : [8bbe7626-57cb-4cc2-b3ab-b8dbbe318adf] Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms | Allocations: 187)
I, [2024-11-21T12:43:33.070521 #145]  INFO -- : [4fb09384-4b71-4a49-9857-45d88d6f4768] Started GET "/patients/pat_obDap4X7n8GgFy6EgdAkK8Qz/medical_certificates/new" for 162.158.79.64 at 2024-11-21 12:43:33 +0000
I, [2024-11-21T12:43:33.075739 #145]  INFO -- : [4fb09384-4b71-4a49-9857-45d88d6f4768] Processing by MedicalCertificatesController#new as HTML
I, [2024-11-21T12:43:33.075783 #145]  INFO -- : [4fb09384-4b71-4a49-9857-45d88d6f4768]   Parameters: {"patient_id"=>"pat_obDap4X7n8GgFy6EgdAkK8Qz"}
I, [2024-11-21T12:43:33.086765 #145]  INFO -- : [4fb09384-4b71-4a49-9857-45d88d6f4768] Completed 200 OK in 11ms (Views: 3.2ms | ActiveRecord: 4.0ms | Allocations: 5109)

HAR: (LINK)

Hey, so at quick look, there’s no issue with your Rails code. Notice that the server times are very stable. As expected, not much has changed in Rails app timings. Most likely the waiting and download time changes are unrelated to your code changes.

The issue is somewhere else: either in your connection or in Render’s routing layer.

If it is really important that you get to the bottom of this, you probably first want to figure out if it is your connection or Render routing layer. Also, if you don’t have that already, set up an APM tool on the app so you get a sense of what kind timing are the users experiencing.

Hi @radanskoric

Thanks for all your support, I was able to learn a lot - as I mentioned I’m kind of new with backend and rails development.

it is really important that you get to the bottom of this, you probably first want to figure out if it is your connection or Render routing layer.

It’s not really important, but I got curious enough to try to understand what was going on. I think I’ll contact Render just in case.

set up an APM tool on the app so you get a sense of what kind timing are the users experiencing

We’ve set up scoutapm, and it confirmed what you said

Thanks again :slight_smile:

I’m glad I could help. :slight_smile: