logger icon indicating copy to clipboard operation
logger copied to clipboard

Log format performance improvement

Open jclusso opened this issue 2 months ago • 0 comments

While doing some log format configuration, I came across this performance improvement. It is 4.61x slower to use strftime compared to iso8601(6). The output format is not identical, but close and has a small improvement that it includes offset IMO. Was wondering if this improvement is worth making a PR?

irb(main):9> time = Time.now
2025-10-10 09:28:08.27533 -0400

irb(main):10> time.strftime("%Y-%m-%dT%H:%M:%S.%6N")
"2025-10-10T09:28:08.275330"

irb(main):11> time.iso8601(6)
"2025-10-10T09:28:08.275330-04:00"
Warming up --------------------------------------
       Time#strftime   149.661k i/100ms
        Time#iso8601   668.851k i/100ms
Calculating -------------------------------------
       Time#strftime      1.459M (± 4.5%) i/s -      7.333M in   5.038060s
        Time#iso8601      6.731M (± 3.8%) i/s -     34.111M in   5.077102s

Comparison:
        Time#iso8601:  6730815.9 i/s
       Time#strftime:  1459156.6 i/s - 4.61x  (± 0.00) slower
Benchmark.ips do |x|
  time = Time.now
  x.report('Time#strftime') { time.strftime('%Y-%m-%dT%H:%M:%S.%6N') }
  x.report('Time#iso8601') { time.iso8601(6) }
  x.compare!
end

https://github.com/ruby/logger/blob/7827b54b0dd796891a508021146607076770b2fb/lib/logger/formatter.rb#L22

jclusso avatar Oct 10 '25 13:10 jclusso