From 3bd8e430f9a6ad30a1222bce686c5d4898f60334 Mon Sep 17 00:00:00 2001 From: Maikel Linke Date: Tue, 28 Mar 2023 09:42:34 +1100 Subject: [PATCH 1/4] Use Rack::Timeout for more realistic tests The closer the test environment is to the production environment the more realistic the tests will be, and the more code we test. We are now able to test the app behaviour on timeouts which I want to do for reports. We can also catch incompatibilities with the rack-timeout gem during testing. --- .env.development | 6 ++++++ Gemfile | 2 +- 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/.env.development b/.env.development index 8f352f7e5f..15e09487f2 100644 --- a/.env.development +++ b/.env.development @@ -11,3 +11,9 @@ OFN_REDIS_URL="redis://localhost:6379/1" OFN_REDIS_JOBS_URL="redis://localhost:6379/2" SITE_URL="0.0.0.0:3000" + +# Deactivate rack-timeout in development. +# https://github.com/zombocom/rack-timeout#configuring +RACK_TIMEOUT_SERVICE_TIMEOUT="0" +RACK_TIMEOUT_WAIT_TIMEOUT="0" +RACK_TIMEOUT_WAIT_OVERTIME="0" diff --git a/Gemfile b/Gemfile index f3e2c8ca40..9b2e9ec007 100644 --- a/Gemfile +++ b/Gemfile @@ -92,6 +92,7 @@ gem 'gmaps4rails' gem 'mimemagic', '> 0.3.5' gem 'paper_trail', '~> 12.1' gem 'rack-rewrite' +gem 'rack-timeout' gem 'roadie-rails' gem 'hiredis' @@ -141,7 +142,6 @@ gem "private_address_check" group :production, :staging do gem 'ddtrace' - gem 'rack-timeout' gem 'sd_notify' # For better Systemd process management. Used by Puma. end From 00a39769055caa5860f30bdb769a134fa25b1af5 Mon Sep 17 00:00:00 2001 From: Maikel Linke Date: Tue, 28 Mar 2023 10:49:07 +1100 Subject: [PATCH 2/4] Display a friendly message when a report times out Once we get a download link for a report, we can display this message sooner. But for now we just use the existing request timeout. --- app/controllers/admin/reports_controller.rb | 10 +++++++++- app/views/admin/reports/show.html.haml | 3 ++- config/locales/en.yml | 5 +++++ spec/system/admin/reports_spec.rb | 13 +++++++++++++ 4 files changed, 29 insertions(+), 2 deletions(-) diff --git a/app/controllers/admin/reports_controller.rb b/app/controllers/admin/reports_controller.rb index 2dc18e4092..10eeed407b 100644 --- a/app/controllers/admin/reports_controller.rb +++ b/app/controllers/admin/reports_controller.rb @@ -26,6 +26,8 @@ module Admin else show_report end + rescue Rack::Timeout::RequestTimeoutException + render_timeout_error end private @@ -36,6 +38,7 @@ module Admin def show_report assign_view_data + @table = render_report_as(:html) if render_data? render "show" end @@ -45,7 +48,6 @@ module Admin @report_subtype = report_subtype @report_title = report_title @rendering_options = rendering_options - @table = render_report_as(:html) if render_data? @data = Reporting::FrontendData.new(spree_current_user) end @@ -66,5 +68,11 @@ module Admin @report.render_as(format) end end + + def render_timeout_error + assign_view_data + @error = ".report_taking_longer" + render "show" + end end end diff --git a/app/views/admin/reports/show.html.haml b/app/views/admin/reports/show.html.haml index 4c93fc9977..0493dfd640 100644 --- a/app/views/admin/reports/show.html.haml +++ b/app/views/admin/reports/show.html.haml @@ -18,7 +18,8 @@ .report__header.print-hidden - if @report.message.present? %p.report__message= @report.message - - if request.post? + - if request.post? && !@error %button.btn-print.icon-print{ onclick: "window.print()"}= t(:report_print) += t(@error) if @error = @table diff --git a/config/locales/en.yml b/config/locales/en.yml index eb520908a0..df589a0d28 100644 --- a/config/locales/en.yml +++ b/config/locales/en.yml @@ -1438,6 +1438,11 @@ en: pack_by_customer: Pack By Customer pack_by_supplier: Pack By Supplier pack_by_product: Pack By Product + show: + report_taking_longer: > + This report is taking longer to process. + It may contain a lot of data or we are busy with other reports. + You can try again later. revenues_by_hub: name: Revenues By Hub description: Revenues by hub diff --git a/spec/system/admin/reports_spec.rb b/spec/system/admin/reports_spec.rb index 33a9cae152..a1e620ae07 100644 --- a/spec/system/admin/reports_spec.rb +++ b/spec/system/admin/reports_spec.rb @@ -44,6 +44,19 @@ describe ' click_button "Go" expect(page).to have_content "EMAIL FIRST NAME" end + + it "displays a friendly timeout message" do + ActiveJob::Base.queue_adapter.perform_enqueued_jobs = false + login_as_admin_and_visit admin_report_path( + report_type: :customers, report_subtype: :mailing_list + ) + expect_any_instance_of(Admin::ReportsController).to receive(:sleep). + and_raise(Rack::Timeout::RequestTimeoutException.new(nil)) + + click_button "Go" + + expect(page).to have_content "This report is taking longer to process." + end end describe "Can access Customers reports and generate customers report" do From 020af0c0e4d7fe930c5e47790f97e766966deb4b Mon Sep 17 00:00:00 2001 From: Maikel Linke Date: Wed, 5 Apr 2023 09:57:48 +1000 Subject: [PATCH 3/4] Explain report timeout better to user --- config/locales/en.yml | 2 +- spec/system/admin/reports_spec.rb | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/config/locales/en.yml b/config/locales/en.yml index df589a0d28..ba116e5e54 100644 --- a/config/locales/en.yml +++ b/config/locales/en.yml @@ -1440,7 +1440,7 @@ en: pack_by_product: Pack By Product show: report_taking_longer: > - This report is taking longer to process. + Sorry, this report took too long to process. It may contain a lot of data or we are busy with other reports. You can try again later. revenues_by_hub: diff --git a/spec/system/admin/reports_spec.rb b/spec/system/admin/reports_spec.rb index a1e620ae07..59c96bf6cc 100644 --- a/spec/system/admin/reports_spec.rb +++ b/spec/system/admin/reports_spec.rb @@ -55,7 +55,7 @@ describe ' click_button "Go" - expect(page).to have_content "This report is taking longer to process." + expect(page).to have_content "this report took too long" end end From 30184ac6aad6928470e8dea5f3bf24419a728496 Mon Sep 17 00:00:00 2001 From: Maikel Linke Date: Tue, 11 Apr 2023 16:44:13 +1000 Subject: [PATCH 4/4] Background reports time out earlier than nginx This allows us to display a friendly message before nginx displays its default error. --- app/controllers/admin/reports_controller.rb | 18 ++++++++++++++++-- spec/system/admin/reports_spec.rb | 4 ++-- 2 files changed, 18 insertions(+), 4 deletions(-) diff --git a/app/controllers/admin/reports_controller.rb b/app/controllers/admin/reports_controller.rb index 10eeed407b..9e75900b8d 100644 --- a/app/controllers/admin/reports_controller.rb +++ b/app/controllers/admin/reports_controller.rb @@ -26,7 +26,7 @@ module Admin else show_report end - rescue Rack::Timeout::RequestTimeoutException + rescue Timeout::Error render_timeout_error end @@ -60,7 +60,9 @@ module Admin job = ReportJob.perform_later( report_class, spree_current_user, params, format ) - sleep 1 until job.done? + Timeout.timeout(max_wait_time) do + sleep 1 until job.done? + end # This result has been rendered by Rails in safe mode already. job.result.html_safe # rubocop:disable Rails/OutputSafety @@ -74,5 +76,17 @@ module Admin @error = ".report_taking_longer" render "show" end + + def max_wait_time + # This value is used by rack-timeout and nginx, usually 30 seconds in + # staging and production: + server_timeout = ENV.fetch("RACK_TIMEOUT_SERVICE_TIMEOUT", "15").to_f + + # Zero disables the timeout: + return 0 if server_timeout.zero? + + # We want to time out earlier than nginx: + server_timeout - 2.seconds + end end end diff --git a/spec/system/admin/reports_spec.rb b/spec/system/admin/reports_spec.rb index 59c96bf6cc..0e255bbdb1 100644 --- a/spec/system/admin/reports_spec.rb +++ b/spec/system/admin/reports_spec.rb @@ -50,8 +50,8 @@ describe ' login_as_admin_and_visit admin_report_path( report_type: :customers, report_subtype: :mailing_list ) - expect_any_instance_of(Admin::ReportsController).to receive(:sleep). - and_raise(Rack::Timeout::RequestTimeoutException.new(nil)) + expect(ENV).to receive(:fetch).with("RACK_TIMEOUT_SERVICE_TIMEOUT", "15") + .and_return("-1") # Negative values time out immediately. click_button "Go"