From c7a1bd944943220aece459365fcd99c06800407b Mon Sep 17 00:00:00 2001 From: Vaidehi Joshi Date: Fri, 7 Feb 2020 07:15:09 -0800 Subject: [PATCH] Fix logging for dev and test environments (#5922) * Fix logging for dev and test environments We had some unused code for Timber in our config files for development and test. However, this was completely clobbering Rails' default behavior of logging out to log/development.log and log/test.log. We should allow for logging in these environments in particular, and since we're not using Timber there, we can just revert to using the Rails default debugging log levels. * Add Timber logger to specs that explicitly require it * Restore default Rails.logger in specs using Timber logger * Explicitly use Rails.logger in OmniauthCallbacksController We seem to have different logger classes leaking into this controller in tests. I'm not entirely sure why this is/haven't been able to investigate yet, but I do think we should be using the Rails.logger explicitly until we can figure that out. --- .../omniauth_callbacks_controller.rb | 30 +++++++++---------- config/environments/development.rb | 8 ++--- config/environments/test.rb | 6 ++-- spec/services/rss_reader_spec.rb | 10 +++++++ spec/system/user_logs_in_with_twitter_spec.rb | 10 +++++++ .../record_db_table_counts_worker_spec.rb | 10 +++++++ 6 files changed, 49 insertions(+), 25 deletions(-) diff --git a/app/controllers/omniauth_callbacks_controller.rb b/app/controllers/omniauth_callbacks_controller.rb index ef1bf1c4f..e01ab2178 100644 --- a/app/controllers/omniauth_callbacks_controller.rb +++ b/app/controllers/omniauth_callbacks_controller.rb @@ -13,14 +13,14 @@ class OmniauthCallbacksController < Devise::OmniauthCallbacksController end def failure - logger.error "Omniauth failure", - omniauth_failure: { - error: request.env["omniauth.error"]&.inspect, - error_type: request.env["omniauth.error.type"].to_s, - auth: request.env["omniauth.auth"], - provider: request.env["omniauth.strategy"].to_s, - cookie: request.env["rack.request.cookie_hash"] - } + Rails.logger.error "Omniauth failure", + omniauth_failure: { + error: request.env["omniauth.error"]&.inspect, + error_type: request.env["omniauth.error.type"].to_s, + auth: request.env["omniauth.auth"], + provider: request.env["omniauth.strategy"].to_s, + cookie: request.env["rack.request.cookie_hash"] + } super end @@ -42,17 +42,17 @@ class OmniauthCallbacksController < Devise::OmniauthCallbacksController else session["devise.#{provider}_data"] = request.env["omniauth.auth"] user_errors = @user.errors.full_messages - logger.error "Log in error: sign in failed. username: #{@user.username} - email: #{@user.email}" - logger.error "Log in error: auth data hash - #{request.env['omniauth.auth']}" - logger.error "Log in error: auth data hash - #{request.env['omniauth.error']&.inspect}" - logger.error "Log in error: user_errors: #{user_errors}" + Rails.logger.error "Log in error: sign in failed. username: #{@user.username} - email: #{@user.email}" + Rails.logger.error "Log in error: auth data hash - #{request.env['omniauth.auth']}" + Rails.logger.error "Log in error: auth data hash - #{request.env['omniauth.error']&.inspect}" + Rails.logger.error "Log in error: user_errors: #{user_errors}" flash[:alert] = user_errors redirect_to new_user_registration_url end rescue StandardError => e - logger.error "Log in error: #{e}" - logger.error "Log in error: auth data hash - #{request.env['omniauth.auth']}" - logger.error "Log in error: auth data hash - #{request.env['omniauth.error']&.inspect}" + Rails.logger.error "Log in error: #{e}" + Rails.logger.error "Log in error: auth data hash - #{request.env['omniauth.auth']}" + Rails.logger.error "Log in error: auth data hash - #{request.env['omniauth.error']&.inspect}" flash[:alert] = "Log in error: #{e}" redirect_to new_user_registration_url end diff --git a/config/environments/development.rb b/config/environments/development.rb index 756e280b3..c76f6c81d 100644 --- a/config/environments/development.rb +++ b/config/environments/development.rb @@ -93,12 +93,8 @@ Rails.application.configure do config.file_watcher = ActiveSupport::EventedFileUpdateChecker - # Install the Timber.io logger - send_logs_to_timber = ENV["SEND_LOGS_TO_TIMBER"] || "false" # <---- set to false to stop sending dev logs to Timber.io - log_device = send_logs_to_timber == "true" ? Timber::LogDevices::HTTP.new(ENV["TIMBER"]) : STDOUT - logger = Timber::Logger.new(log_device) - logger.level = config.log_level - config.logger = ActiveSupport::TaggedLogging.new(logger) + # Debug is the default log_level, but can be changed per environment. + config.log_level = :debug # See for other config options config.after_initialize do diff --git a/config/environments/test.rb b/config/environments/test.rb index 724719819..df9b63ae8 100644 --- a/config/environments/test.rb +++ b/config/environments/test.rb @@ -54,10 +54,8 @@ Rails.application.configure do config.active_job.queue_adapter = :test - # Install the Timber.io logger, but do not send logs. - logger = Timber::Logger.new(nil) - logger.level = config.log_level - config.logger = ActiveSupport::TaggedLogging.new(logger) + # Debug is the default log_level, but can be changed per environment. + config.log_level = :debug # enable Bullet in testing mode only if requested config.after_initialize do diff --git a/spec/services/rss_reader_spec.rb b/spec/services/rss_reader_spec.rb index 5d64e1225..e359298d4 100644 --- a/spec/services/rss_reader_spec.rb +++ b/spec/services/rss_reader_spec.rb @@ -6,12 +6,22 @@ vcr_option = { allow_playback_repeats: "true" } +default_logger = Rails.logger + RSpec.describe RssReader, type: :service, vcr: vcr_option do let(:link) { "https://medium.com/feed/@vaidehijoshi" } let(:nonmedium_link) { "https://circleci.com/blog/feed.xml" } let(:nonpermanent_link) { "https://medium.com/feed/@macsiri/" } let(:rss_data) { RSS::Parser.parse(HTTParty.get(link).body, false) } + # Override the default Rails logger as these tests require the Timber logger. + before do + timber_logger = Timber::Logger.new(nil) + Rails.logger = ActiveSupport::TaggedLogging.new(timber_logger) + end + + after { Rails.logger = default_logger } + describe "#get_all_articles" do before do [link, nonmedium_link, nonpermanent_link].each do |feed_url| diff --git a/spec/system/user_logs_in_with_twitter_spec.rb b/spec/system/user_logs_in_with_twitter_spec.rb index a7dad69dc..5ef9c4b2f 100644 --- a/spec/system/user_logs_in_with_twitter_spec.rb +++ b/spec/system/user_logs_in_with_twitter_spec.rb @@ -32,6 +32,16 @@ RSpec.describe "Authenticating with twitter" do } end + default_logger = Rails.logger + + # Override the default Rails logger as these tests require the Timber logger. + before do + timber_logger = Timber::Logger.new(nil) + Rails.logger = ActiveSupport::TaggedLogging.new(timber_logger) + end + + after { Rails.logger = default_logger } + context "when user is new on dev.to" do it "logging in with twitter using valid credentials" do user_grants_authorization_on_twitter_popup(twitter_callback_hash) diff --git a/spec/workers/metrics/record_db_table_counts_worker_spec.rb b/spec/workers/metrics/record_db_table_counts_worker_spec.rb index 474a2b178..90fd5ee20 100644 --- a/spec/workers/metrics/record_db_table_counts_worker_spec.rb +++ b/spec/workers/metrics/record_db_table_counts_worker_spec.rb @@ -1,9 +1,19 @@ require "rails_helper" RSpec.describe Metrics::RecordDbTableCountsWorker, type: :worker do + default_logger = Rails.logger + include_examples "#enqueues_on_correct_queue", "low_priority", 1 describe "#perform" do + # Override the default Rails logger as these tests require the Timber logger. + before do + timber_logger = Timber::Logger.new(nil) + Rails.logger = ActiveSupport::TaggedLogging.new(timber_logger) + end + + after { Rails.logger = default_logger } + it "logs estimated counts in Datadog" do allow(DataDogStatsClient).to receive(:gauge) described_class.new.perform