Repository: rails/rails
File: activejob/test/cases/logging_test.rb (Ruby)

Code before:

    EnqueueErrorJob.set(wait: 1.hour).perform_later
    assert_match(/Failed enqueuing EnqueueErrorJob to EnqueueError\(default\): ActiveJob::EnqueueError \(There was an error enqueuing the job\)/, @logger.messages)
  end

  def test_for_tagged_logger_support_is_consistent
    set_logger ::Logger.new(nil)
    assert_nothing_raised do
      OverriddenLoggingJob.perform_later "Dummy"
    end
  end

  def test_job_error_logging
    perform_enqueued_jobs do
      RescueJob.perform_later "other"
    rescue RescueJob::OtherError
      assert_match(/Performing RescueJob \(Job ID: .*?\) from .*? with arguments:.*other/, @logger.messages)
      assert_match(/Error performing RescueJob \(Job ID: .*?\) from .*? in .*ms: RescueJob::OtherError \(Bad hair\):\n.*\brescue_job\.rb:\d+:in .*perform'/, @logger.messages)
    end
  end

  def test_job_error_logging_backtrace_cleaner
    perform_enqueued_jobs do
      RescueJob.perform_later "other"
    rescue RescueJob::OtherError
      assert_match(/rescue_job\.rb:\d+:in .*perform'/, @logger.messages)
      assert_empty(@logger.messages.lines.grep(/minitest\//))
      assert_empty(@logger.messages.lines.grep(/gems\//))
    end
  end

  def test_job_no_error_logging_on_rescuable_job
    perform_enqueued_jobs { RescueJob.perform_later "david" }
    assert_match(/Performing RescueJob \(Job ID: .*?\) from .*? with arguments:.*david/, @logger.messages)
    assert_no_match(/Error performing RescueJob \(Job ID: .*?\) from .*? in .*ms: ArgumentError \(Hair too good\):\n.*\brescue_job\.rb:\d+:in .*perform'/, @logger.messages)
  end

  unless adapter_is?(:inline, :sneakers)
    def test_enqueue_retry_logging
      perform_enqueued_jobs do
        RetryJob.perform_later "DefaultsError", 2
        assert_match(/Retrying RetryJob \(Job ID: .*?\) after \d+ attempts in 3 seconds, due to a DefaultsError.*\./, @logger.messages)
      end
    end
  end

  def test_enqueue_retry_logging_on_retry_job
    perform_enqueued_jobs { RescueJob.perform_later "david" }
    assert_match(/Retrying RescueJob \(Job ID: .*?\) after \d+ attempts in 0 seconds\./, @logger.messages)
  end


Review comment (suggestion):
I see you copied what was done above, but this should be an `assert_raise`, otherwise if `RescueJob.perform_later "other"` stop raising the test will pass.

Code after:

    EnqueueErrorJob.set(wait: 1.hour).perform_later
    assert_match(/Failed enqueuing EnqueueErrorJob to EnqueueError\(default\): ActiveJob::EnqueueError \(There was an error enqueuing the job\)/, @logger.messages)
  end

  def test_for_tagged_logger_support_is_consistent
    set_logger ::Logger.new(nil)
    assert_nothing_raised do
      OverriddenLoggingJob.perform_later "Dummy"
    end
  end

  def test_job_error_logging
    perform_enqueued_jobs do
      RescueJob.perform_later "other"
    rescue RescueJob::OtherError
      assert_match(/Performing RescueJob \(Job ID: .*?\) from .*? with arguments:.*other/, @logger.messages)
      assert_match(/Error performing RescueJob \(Job ID: .*?\) from .*? in .*ms: RescueJob::OtherError \(Bad hair\):\n.*\brescue_job\.rb:\d+:in .*perform'/, @logger.messages)
    end
  end

  def test_job_error_logging_backtrace_cleaner
    perform_enqueued_jobs do
      assert_raises(RescueJob::OtherError) do
        RescueJob.perform_later "other"
      end
    end

    assert_match(/rescue_job\.rb:\d+:in .*perform'/, @logger.messages)
    assert_empty(@logger.messages.lines.grep(/minitest\//))
    assert_empty(@logger.messages.lines.grep(/gems\//))
  end

  def test_job_no_error_logging_on_rescuable_job
    perform_enqueued_jobs { RescueJob.perform_later "david" }
    assert_match(/Performing RescueJob \(Job ID: .*?\) from .*? with arguments:.*david/, @logger.messages)
    assert_no_match(/Error performing RescueJob \(Job ID: .*?\) from .*? in .*ms: ArgumentError \(Hair too good\):\n.*\brescue_job\.rb:\d+:in .*perform'/, @logger.messages)
  end

  unless adapter_is?(:inline, :sneakers)
    def test_enqueue_retry_logging
      perform_enqueued_jobs do
        RetryJob.perform_later "DefaultsError", 2
        assert_match(/Retrying RetryJob \(Job ID: .*?\) after \d+ attempts in 3 seconds, due to a DefaultsError.*\./, @logger.messages)
      end
    end
  end

  def test_enqueue_retry_logging_on_retry_job
    perform_enqueued_jobs { RescueJob.perform_later "david" }
    assert_match(/Retrying RescueJob \(Job ID: .*?\) after \d+ attempts in 0 seconds\./, @logger.messages)