From 3f0e76710626a72d321b7c26bdf7eedb0f2e595a Mon Sep 17 00:00:00 2001 From: Jarek Radosz Date: Thu, 5 May 2022 03:53:54 +0200 Subject: [PATCH] DEV: Use `FakeLogger` in RequestTracker specs (#16640) `TestLogger` was responsible for some flaky specs runs: ``` Error during failsafe response: undefined method `debug' for # Did you mean? debugger ``` This commit also cleans up other uses of `FakeLogger` --- .../migrate_badge_image_to_uploads_spec.rb | 8 ++--- spec/jobs/migrate_group_flair_images_spec.rb | 4 +-- spec/lib/discourse_hub_spec.rb | 4 +-- spec/lib/discourse_spec.rb | 6 ++-- spec/lib/email/processor_spec.rb | 9 +---- spec/lib/middleware/request_tracker_spec.rb | 36 ++++++------------- spec/models/report_spec.rb | 4 +-- spec/models/theme_spec.rb | 4 +-- spec/requests/application_controller_spec.rb | 9 ++--- spec/requests/csp_reports_controller_spec.rb | 2 +- 10 files changed, 30 insertions(+), 56 deletions(-) diff --git a/spec/jobs/migrate_badge_image_to_uploads_spec.rb b/spec/jobs/migrate_badge_image_to_uploads_spec.rb index 29277fb15f2..43794ee17dc 100644 --- a/spec/jobs/migrate_badge_image_to_uploads_spec.rb +++ b/spec/jobs/migrate_badge_image_to_uploads_spec.rb @@ -1,6 +1,6 @@ # frozen_string_literal: true -RSpec.describe Jobs::MigrateBadgeImageToUploads do +describe Jobs::MigrateBadgeImageToUploads do let(:image_url) { "https://omg.aws.somestack/test.png" } let(:badge) { Fabricate(:badge) } @@ -35,8 +35,8 @@ RSpec.describe Jobs::MigrateBadgeImageToUploads do it 'should skip badges with invalid flair URLs' do DB.exec("UPDATE badges SET image = 'abc' WHERE id = ?", badge.id) described_class.new.execute_onceoff({}) - expect(Rails.logger.warnings.count).to eq(0) - expect(Rails.logger.errors.count).to eq(0) + expect(@fake_logger.warnings.count).to eq(0) + expect(@fake_logger.errors.count).to eq(0) end # this case has a couple of hacks that are needed to test this behavior, so if it @@ -58,6 +58,6 @@ RSpec.describe Jobs::MigrateBadgeImageToUploads do expect(badge.image_upload).to eq(nil) expect(badge.image_url).to eq(nil) expect(Badge.where(id: badge.id).select(:image).first[:image]).to eq(image_url) - expect(Rails.logger.warnings.count).to eq(3) + expect(@fake_logger.warnings.count).to eq(3) end end diff --git a/spec/jobs/migrate_group_flair_images_spec.rb b/spec/jobs/migrate_group_flair_images_spec.rb index d044c1cc0f9..e2c03802a5b 100644 --- a/spec/jobs/migrate_group_flair_images_spec.rb +++ b/spec/jobs/migrate_group_flair_images_spec.rb @@ -1,6 +1,6 @@ # frozen_string_literal: true -RSpec.describe Jobs::MigrateGroupFlairImages do +describe Jobs::MigrateGroupFlairImages do let(:image_url) { "https://omg.aws.somestack/test.png" } let(:group) { Fabricate(:group) } @@ -35,6 +35,6 @@ RSpec.describe Jobs::MigrateGroupFlairImages do it 'should skip groups with invalid flair URLs' do DB.exec("UPDATE groups SET flair_url = 'abc' WHERE id = #{group.id}") described_class.new.execute_onceoff({}) - expect(Rails.logger.warnings.count).to eq(0) + expect(@fake_logger.warnings.count).to eq(0) end end diff --git a/spec/lib/discourse_hub_spec.rb b/spec/lib/discourse_hub_spec.rb index 2af523777f5..e42cd4202c8 100644 --- a/spec/lib/discourse_hub_spec.rb +++ b/spec/lib/discourse_hub_spec.rb @@ -91,11 +91,11 @@ describe DiscourseHub do DiscourseHub.collection_action(:get, '/test') - expect(Rails.logger.warnings).to eq([ + expect(@fake_logger.warnings).to eq([ DiscourseHub.response_status_log_message('/test', 500), ]) - expect(Rails.logger.errors).to eq([ + expect(@fake_logger.errors).to eq([ DiscourseHub.response_body_log_message("") ]) end diff --git a/spec/lib/discourse_spec.rb b/spec/lib/discourse_spec.rb index 5fbdffa6453..b41d11dd2c7 100644 --- a/spec/lib/discourse_spec.rb +++ b/spec/lib/discourse_spec.rb @@ -383,19 +383,19 @@ describe Discourse do expect(old_method_caller(k)).to include("discourse_spec") expect(old_method_caller(k)).to include(k) - expect(Rails.logger.warnings).to eq([old_method_caller(k)]) + expect(@fake_logger.warnings).to eq([old_method_caller(k)]) end it 'can report the deprecated version' do Discourse.deprecate(SecureRandom.hex, since: "2.1.0.beta1") - expect(Rails.logger.warnings[0]).to include("(deprecated since Discourse 2.1.0.beta1)") + expect(@fake_logger.warnings[0]).to include("(deprecated since Discourse 2.1.0.beta1)") end it 'can report the drop version' do Discourse.deprecate(SecureRandom.hex, drop_from: "2.3.0") - expect(Rails.logger.warnings[0]).to include("(removal in Discourse 2.3.0)") + expect(@fake_logger.warnings[0]).to include("(removal in Discourse 2.3.0)") end it 'can raise deprecation error' do diff --git a/spec/lib/email/processor_spec.rb b/spec/lib/email/processor_spec.rb index 903d0890f2e..f789670b0cc 100644 --- a/spec/lib/email/processor_spec.rb +++ b/spec/lib/email/processor_spec.rb @@ -49,7 +49,6 @@ describe Email::Processor do end describe "rate limits" do - let(:mail) { "From: #{from}\nTo: bar@foo.com\nSubject: FOO BAR\n\nFoo foo bar bar?" } let(:limit_exceeded) { RateLimiter::LimitExceeded.new(10) } @@ -68,11 +67,9 @@ describe Email::Processor do expect { Email::Processor.process!(mail, retry_on_rate_limit: false) }.to raise_error(limit_exceeded) end end - end context "known error" do - let(:mail) { "From: #{from}\nTo: bar@foo.com" } let(:mail2) { "From: #{from}\nTo: foo@foo.com" } let(:mail3) { "From: #{from}\nTo: foobar@foo.com" } @@ -101,7 +98,6 @@ describe Email::Processor do end context "unrecognized error" do - let(:mail) { "Date: Fri, 15 Jan 2016 00:12:43 +0100\nFrom: #{from}\nTo: bar@foo.com\nSubject: FOO BAR\n\nFoo foo bar bar?" } let(:mail2) { "Date: Fri, 15 Jan 2016 00:12:43 +0100\nFrom: #{from}\nTo: foo@foo.com\nSubject: BAR BAR\n\nBar bar bar bar?" } @@ -115,7 +111,7 @@ describe Email::Processor do Email::Processor.process!(mail) - errors = Rails.logger.errors + errors = @fake_logger.errors expect(errors.size).to eq(1) expect(errors.first).to include("boom") @@ -142,11 +138,9 @@ describe Email::Processor do Email::Processor.process!(mail2) }.to change { EmailLog.count }.by(1) end - end context "from reply to email address" do - let(:mail) { "Date: Fri, 15 Jan 2016 00:12:43 +0100\nFrom: reply@bar.com\nTo: reply@bar.com\nSubject: FOO BAR\n\nFoo foo bar bar?" } it "ignores the email" do @@ -156,7 +150,6 @@ describe Email::Processor do Email::Processor.process!(mail) }.to change { EmailLog.count }.by(0) end - end context "mailinglist mirror" do diff --git a/spec/lib/middleware/request_tracker_spec.rb b/spec/lib/middleware/request_tracker_spec.rb index 9c87b7e2677..89700540d86 100644 --- a/spec/lib/middleware/request_tracker_spec.rb +++ b/spec/lib/middleware/request_tracker_spec.rb @@ -24,7 +24,6 @@ describe Middleware::RequestTracker do end context "full request" do - it "can handle rogue user agents" do agent = (+"Evil Googlebot String \xc3\x28").force_encoding("Windows-1252") @@ -35,12 +34,11 @@ describe Middleware::RequestTracker do expect(WebCrawlerRequest.where(user_agent: agent.encode('utf-8')).count).to eq(1) end - end context "log_request" do before do - freeze_time Time.now + freeze_time ApplicationRequest.clear_cache! end @@ -128,7 +126,7 @@ describe Middleware::RequestTracker do expect(ApplicationRequest.page_view_anon.first.count).to eq(1) end - context "ignore_anonymous_pageviews" do + context "ignore anonymous page views" do let(:anon_data) do Middleware::RequestTracker.get_data(env( "HTTP_USER_AGENT" => "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.72 Safari/537.36" @@ -183,26 +181,13 @@ describe Middleware::RequestTracker do end context "rate limiting" do - - class TestLogger - attr_accessor :warnings - - def initialize - @warnings = 0 - end - - def warn(*args) - @warnings += 1 - end - end - before do RateLimiter.enable RateLimiter.clear_all_global! RateLimiter.clear_all! - @old_logger = Rails.logger - Rails.logger = TestLogger.new + @orig_logger = Rails.logger + Rails.logger = @fake_logger = FakeLogger.new # rate limiter tests depend on checks for retry-after # they can be sensitive to clock skew during test runs @@ -210,7 +195,7 @@ describe Middleware::RequestTracker do end after do - Rails.logger = @old_logger + Rails.logger = @orig_logger end let :middleware do @@ -244,7 +229,7 @@ describe Middleware::RequestTracker do status, _ = middleware.call(env1) status, _ = middleware.call(env1) - expect(Rails.logger.warnings).to eq(warn_count) + expect(@fake_logger.warnings.count { |w| w.include?("Global IP rate limit exceeded") }).to eq(warn_count) expect(status).to eq(429) warn_count += 1 end @@ -322,7 +307,7 @@ describe Middleware::RequestTracker do status, _ = middleware.call(env1) status, _ = middleware.call(env1) - expect(Rails.logger.warnings).to eq(0) + expect(@fake_logger.warnings.count { |w| w.include?("Global IP rate limit exceeded") }).to eq(0) expect(status).to eq(200) end end @@ -334,7 +319,7 @@ describe Middleware::RequestTracker do status, _ = middleware.call(env) status, headers = middleware.call(env) - expect(Rails.logger.warnings).to eq(1) + expect(@fake_logger.warnings.count { |w| w.include?("Global IP rate limit exceeded") }).to eq(1) expect(status).to eq(429) expect(headers["Retry-After"]).to eq("10") end @@ -346,7 +331,7 @@ describe Middleware::RequestTracker do status, _ = middleware.call(env) status, _ = middleware.call(env) - expect(Rails.logger.warnings).to eq(1) + expect(@fake_logger.warnings.count { |w| w.include?("Global IP rate limit exceeded") }).to eq(1) expect(status).to eq(200) end @@ -577,7 +562,7 @@ describe Middleware::RequestTracker do end end - let :logger do + let(:logger) do ->(env, data) do @env = env @data = data @@ -620,7 +605,6 @@ describe Middleware::RequestTracker do end it "can correctly log detailed data" do - global_setting :enable_performance_http_headers, true # ensure pg is warmed up with the select 1 query diff --git a/spec/models/report_spec.rb b/spec/models/report_spec.rb index 1468517c37e..32976e14269 100644 --- a/spec/models/report_spec.rb +++ b/spec/models/report_spec.rb @@ -209,7 +209,7 @@ describe Report do end context "with #{request_type}" do - before(:each) do + before do freeze_time DateTime.parse('2017-03-01 12:00') application_requests = [ { date: 35.days.ago.to_time, req_type: ApplicationRequest.req_types[request_type.to_s], count: 35 }, @@ -893,7 +893,7 @@ describe Report do expect(report).to be_nil - expect(Rails.logger.errors).to eq([ + expect(@fake_logger.errors).to eq([ 'Couldn’t create report `signups`: ' ]) end diff --git a/spec/models/theme_spec.rb b/spec/models/theme_spec.rb index 6580cc5631d..a14f10e5b8a 100644 --- a/spec/models/theme_spec.rb +++ b/spec/models/theme_spec.rb @@ -614,7 +614,7 @@ HTML it 'warns when the theme has modified the setting type but data cannot be converted' do begin @orig_logger = Rails.logger - Rails.logger = FakeLogger.new + Rails.logger = @fake_logger = FakeLogger.new theme.set_field(target: :settings, name: :yaml, value: "valid_json_schema_setting:\n default: \"\"\n type: \"list\"") theme.save! @@ -628,7 +628,7 @@ HTML theme.convert_settings expect(setting.value).to eq("red,globe") - expect(Rails.logger.warnings[0]).to include("Theme setting type has changed but cannot be converted.") + expect(@fake_logger.warnings[0]).to include("Theme setting type has changed but cannot be converted.") ensure Rails.logger = @orig_logger end diff --git a/spec/requests/application_controller_spec.rb b/spec/requests/application_controller_spec.rb index ada978395cf..bbf0fd23695 100644 --- a/spec/requests/application_controller_spec.rb +++ b/spec/requests/application_controller_spec.rb @@ -375,7 +375,6 @@ RSpec.describe ApplicationController do end describe 'no logspam' do - before do @orig_logger = Rails.logger Rails.logger = @fake_logger = FakeLogger.new @@ -386,7 +385,6 @@ RSpec.describe ApplicationController do end it 'should handle 404 to a css file' do - Discourse.cache.delete("page_not_found_topics:#{I18n.locale}") topic1 = Fabricate(:topic) @@ -400,10 +398,9 @@ RSpec.describe ApplicationController do expect(response.body).to include(topic1.title) expect(response.body).to_not include(topic2.title) - expect(Rails.logger.fatals.length).to eq(0) - expect(Rails.logger.errors.length).to eq(0) - expect(Rails.logger.warnings.length).to eq(0) - + expect(@fake_logger.fatals.length).to eq(0) + expect(@fake_logger.errors.length).to eq(0) + expect(@fake_logger.warnings.length).to eq(0) end end diff --git a/spec/requests/csp_reports_controller_spec.rb b/spec/requests/csp_reports_controller_spec.rb index 15d28772c9e..87ecbcd6daa 100644 --- a/spec/requests/csp_reports_controller_spec.rb +++ b/spec/requests/csp_reports_controller_spec.rb @@ -50,7 +50,7 @@ describe CspReportsController do it 'logs the violation report' do send_report - expect(Rails.logger.warnings).to include("CSP Violation: 'http://suspicio.us/assets.js' \n\nconsole.log('unsafe')") + expect(@fake_logger.warnings).to include("CSP Violation: 'http://suspicio.us/assets.js' \n\nconsole.log('unsafe')") end end end