Why does the Rails.logger write to the same log file in development and test?

Question

I have the following model test:

  describe 'Checking for errors' do
    it 'should check for any jobs that have errors and log them' do
      logger = Logger.new('log/go_job_errors_test.log')
      code_location = create(:code_location_with_best_code_set)
      code_location.jobs << create(:complete_job, status: 3, exception: 'I failed to complete')
      CodeLocationJobFeeder.create(code_location_id: code_location.id, url: code_location.repository.url, status: 2)
      CodeLocationJobFeeder.check_for_errors(1)
      logger.expects(:info).with("I failed to complete")
    end

With the following model code:

def check_for_errors(amount)
  processed.limit(amount).each do |code_location_job_feeder|
    code_location = CodeLocation.includes(:jobs).find(code_location_job_feeder.code_location_id)
    log_error(code_location) unless code_location.jobs.last.status != 3
  end
end

private

def log_error(code_location)
  logger = Logger.new('log/go_job_errors.log')
  failed_job = code_location.jobs.last
  logger.info do
    "Job #{failed_job.id} with code location: #{code_location.id} failed. Exception: #{failed_job.exception}"
  end
end

The gist of the test is that when I execute CodeLocationJobFeeder.check_for_errors I'll have a separate log file that will tell me all the info that I want concerning some errors. This works fine in development and I get the file that I want. However when I run the test, I get output in both log/go_job_errors_test.log and log/go_job_errors.log with the following output:

log/go_job_errors.log

[2017-06-28T18:23:46.164141 #29604]  INFO -- : Job 40 with code location: 93 failed. Exception: I failed to complete

This is the content that I want but in the wrong file. Here is the second file:

 log/go_job_error_test.log

 # Logfile created on 2017-06-28 18:40:59 +0000 by logger.rb/47272

The correct file with the wrong content.

I've been trying to apply this s.o. answer Logger test but it doesn't seem to be working too great. Can someone help point out what I'm doing wrong?

Because the logger you create in your tests is ignored. Nobody uses it. Model writes to its own logger. — Sergio Tulentsev, Jun 29 '17 at 06:32

score 1 · Accepted Answer · answered Jun 29 '17 at 06:29

This line "Logger.new('log/go_job_errors.log')" in the model instructs to log model errors to this file 'log/go_job_errors.log'. Irrespective of environment, the model errors are always logged here 'log/go_job_errors.log'

In your tests, you start with this line 'Logger.new('log/go_job_errors_test.log')', this line creates a new log file. And when your test calls the model, the model calls 'log_error(code_location)', but that method only logs to 'log/go_job_errors.log'.

Why does the Rails.logger write to the same log file in development and test?

1 Answers1