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
Rails.logger.info(<<~TEXT)
Response from example.com:
Status: 200
Body: It works!
TEXT
With that, the following is written to your log file.
I, [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:
Rails.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:
I, [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:
def 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.