Logging multiple lines in Rails without making filtering your logs difficult

Rails' default logger prefixes each log entry with timestamp and tags (like request ID).
For multi-line entries, only the first line is prefixed which can give you a hard time when grepping logs.

Example

CopyRails.logger.info(<<~TEXT)
  Response from example.com:
  Status: 200
  Body: It works!
TEXT

With that, the following is written to your log file.

CopyI, [2024-10-04T08:12:16.576463 #1917250]  INFO -- : [97e45eae-a220-412d-96ad-e9e148ead71d] Response from example.com:
Status: 200
Body: It works!

If you then run grep 97e45eae-a220-412d-96ad-e9e148ead71d log/production.log, only the first line is printed.

A simple solution

While there are lots of different ways to log (e.g. using specific gems, other log formats, or logging to external services), here is a low-tech solution that works well:

CopyRails.logger.info('Response from example.com:')
Rails.logger.info('  Status: 200')
Rails.logger.info('  Body: It works!')

Now all lines are prefixed with timestamp and tags:

CopyI, [2024-10-04T08:13:23.193693 #1917250]  INFO -- : [97e45eae-a220-412d-96ad-e9e148ead71d] Response from example.com:
I, [2024-10-04T08:13:23.194007 #1917250]  INFO -- : [97e45eae-a220-412d-96ad-e9e148ead71d]   Status: 200
I, [2024-10-04T08:13:23.194047 #1917250]  INFO -- : [97e45eae-a220-412d-96ad-e9e148ead71d]   Body: It works! 

Improving our simple solution

If you don't want to repeat yourself, or can't control each logged line (e.g. when logging multi-line responses from an API), define a method which does the above for you:

Copydef log(message)
  message.each_line do |line|
    Rails.logger.info(line.rstrip)
  end
end

You can then call log with your multi-line string and each line will be tagged.

To improve even further, you could easily implement a small custom logger which does the same.