Project

General

Profile

Actions
Copy link

Bug #7968

open

Poor UDPSocket#send performance in ruby 2.0.0 on windows

Added by cs96and (Alan Davies) almost 12 years ago. Updated about 1 year ago.

Status:
Assigned
Assignee:
windows
Target version:
-
ruby -v:
ruby 2.0.0p0 (2013-02-24) [x64-mingw32]
Backport:
[ruby-core:52936]
Tags:
ext, perf

Description

I have noticed that the performance of UDPSocket#send on ruby 2.0.0 on windows is much poorer than that of 1.9.3 or 1.8.7. Running the attahced script on 2.0.0 gives the following...

d:\scripts>bash -c "ruby --version"
ruby 2.0.0p0 (2013-02-24) [x64-mingw32]

d:\scripts>bash -c "time ruby socketsendtest.rb"

real 0m2.572s
user 0m0.000s
sys 0m0.016s

However, running the same test with 1.9.3 is much faster...

d:\scripts>pik 193

d:\scripts>bash -c "ruby --version"
ruby 1.9.3p374 (2013-01-15) [i386-mingw32]

d:\scripts>bash -c "time ruby socketsendtest.rb"

real 0m0.993s
user 0m0.015s
sys 0m0.016s

Additionally, if I change the send call to a print (commented out in the script), then the performance is fine on 2.0.0....

d:\scripts>pik 200

d:\scripts>bash -c "ruby --version"
ruby 2.0.0p0 (2013-02-24) [x64-mingw32]

d:\scripts>bash -c "time ruby socketsendtest.rb"

real 0m0.907s
user 0m0.000s
sys 0m0.015s

What is send() doing that print() doesn't do that is causing the massive performance drop?

Thanks
Alan.

Files

socketsendtest.rb (266 Bytes) socketsendtest.rb Script to test UDPSocket#send cs96and (Alan Davies), 02/26/2013 08:55 PM
Actions
Copy link
 #1

Updated by drbrain (Eric Hodel) almost 12 years ago

  • Status changed from Open to Closed
  • % Done changed from 0 to 100

This issue was solved with changeset r39542.
Alan, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.

  • lib/rubygems/ext/builder.rb: Fix incompatibilities when installing
    extensions. Patch by Nobu.
    [ruby-trunk - Bug #7968] [ruby-trunk - Bug #7971]

  • lib/rubygems/ext/ext_conf_builder.rb: ditto.

  • lib/rubygems/installer.rb: ditto.

  • test/rubygems/test_gem_ext_ext_conf_builder.rb: Test for the above.

  • test/rubygems/test_gem_installer.rb: ditto.

  • lib/rubygems/commands/sources_command.rb: Prefer HTTPS over HTTP.

  • lib/rubygems/defaults.rb: ditto

  • lib/rubygems/dependency_resolver.rb: Ditto.

  • lib/rubygems/source.rb: ditto.

  • lib/rubygems/spec_fetcher.rb: ditto.

  • lib/rubygems/specification.rb: ditto.

  • lib/rubygems/test_utilities.rb: ditto.

  • test/rubygems/test_gem.rb: Test for the above.

  • test/rubygems/test_gem_commands_sources_command.rb: ditto.

  • test/rubygems/test_gem_dependency_resolver_api_set.rb: ditto.

  • test/rubygems/test_gem_remote_fetcher.rb: ditto.

  • test/rubygems/test_gem_source.rb: ditto.

  • test/rubygems/test_gem_spec_fetcher.rb: ditto.

Actions
Copy link
 #2 [ruby-core:53075]

Updated by nagachika (Tomoyuki Chikanaga) almost 12 years ago

  • % Done changed from 100 to 0
  • Status changed from Closed to Open
Actions
Copy link
 #3 [ruby-core:53147]

Updated by cs96and (Alan Davies) almost 12 years ago

I see the %Done went up to 100 and back down to zero. Is this fixed or not now?

Thanks
Alan.

Actions
Copy link
 #4 [ruby-core:53148]

Updated by nagachika (Tomoyuki Chikanaga) almost 12 years ago

Hello, Alan.

I re-open this ticket because it was accidentally closed by wrong commit message.
This issue is not fixed yet.

BTW, in socketsendtest.rb UDPSocket#bind and #connect receive different port number. Is it right?
On my environment, I've got an exception.

socketsendtest.rb:9:in `send': Connection refused - send(2) (Errno::ECONNREFUSED)

Thanks

Actions
Copy link
 #5 [ruby-core:53270]

Updated by cs96and (Alan Davies) almost 12 years ago

The bind and connect can be different. The bind specifies what port you are sending from, and connect specifies the port you are sending to (the ip address can be a different box too). It runs fine for me with different ports, but you can make them the same if you want.

Actions
Copy link
 #6 [ruby-core:55780]

Updated by cs96and (Alan Davies) over 11 years ago

Any update on this?

Thanks
Alan

Actions
Copy link
 #7 [ruby-core:55843]

Updated by luislavena (Luis Lavena) over 11 years ago

  • Status changed from Open to Assigned
  • Assignee changed from windows to usa (Usaku NAKAMURA)

Any suggestion about this?

Actions
Copy link
 #8

Updated by cs96and (Alan Davies) almost 11 years ago

This is still a problem in 2.0.0-p353 on windows. Is there any update?

Thanks
Alan.

Actions
Copy link
 #9

Updated by cs96and (Alan Davies) almost 11 years ago

Issue #7968 has been updated by Alan Davies.

This is still a problem in 2.0.0-p353 on windows. Is there any update?

Thanks
Alan.

Bug #7968: Poor UDPSocket#send performance in ruby 2.0.0 on windows
https://bugs.ruby-lang.org/issues/7968#change-44343

  • Author: Alan Davies
  • Status: Assigned
  • Priority: Normal
  • Assignee: Usaku NAKAMURA
  • Category: platform/windows
  • Target version:
  • ruby -v: ruby 2.0.0p0 (2013-02-24) [x64-mingw32]
  • Backport:

I have noticed that the performance of UDPSocket#send on ruby 2.0.0 on windows is much poorer than that of 1.9.3 or 1.8.7. Running the attahced script on 2.0.0 gives the following...

d:\scripts>bash -c "ruby --version"
ruby 2.0.0p0 (2013-02-24) [x64-mingw32]

d:\scripts>bash -c "time ruby socketsendtest.rb"

real 0m2.572s
user 0m0.000s
sys 0m0.016s

However, running the same test with 1.9.3 is much faster...

d:\scripts>pik 193

d:\scripts>bash -c "ruby --version"
ruby 1.9.3p374 (2013-01-15) [i386-mingw32]

d:\scripts>bash -c "time ruby socketsendtest.rb"

real 0m0.993s
user 0m0.015s
sys 0m0.016s

Additionally, if I change the send call to a print (commented out in the script), then the performance is fine on 2.0.0....

d:\scripts>pik 200

d:\scripts>bash -c "ruby --version"
ruby 2.0.0p0 (2013-02-24) [x64-mingw32]

d:\scripts>bash -c "time ruby socketsendtest.rb"

real 0m0.907s
user 0m0.000s
sys 0m0.015s

What is send() doing that print() doesn't do that is causing the massive performance drop?

Thanks
Alan.

---Files--------------------------------
socketsendtest.rb (266 Bytes)

--
http://bugs.ruby-lang.org/

Actions
Copy link
 #10 [ruby-core:83475]

Updated by usa (Usaku NAKAMURA) about 7 years ago

  • Assignee changed from usa (Usaku NAKAMURA) to windows
Actions
Copy link
 #11 [ruby-core:83512]

Updated by MSP-Greg (Greg L) about 7 years ago

I ran this up on Appveyor using all minor versions 1.9.3 thru trunk. The code loop is one of two:

100000.times { s.send(str, 0) }

100000.times { s.print(str) }

One set was run with str.length = 10, the other with str.length = 2000. String length didn't really affect test times...

When using send, 1.9.3 is fastest, 2.0.0 is slowest, others were in between. When using print, 1.9.3 thru 2.1.9 are faster by approx 2x compared to 2.2.6 thru trunk.

Anyway, not that well versed in all the uses of sockets, so I can't judge whether these time differences are 'real world' significant. Also, not a terribly scientific test...

  10 Characters Send

 0.56247  ruby 1.9.3p551 (2014-11-13) [i386-mingw32]
 1.70312  ruby 2.0.0p648 (2015-12-16) [x64-mingw32]
 1.00000  ruby 2.1.9p490 (2016-03-30 revision 54437) [x64-mingw32]
 0.98534  ruby 2.2.6p396 (2016-11-15 revision 56800) [x64-mingw32]
 0.93747  ruby 2.3.3p222 (2016-11-21 revision 56859) [x64-mingw32]
 0.95312  ruby 2.4.1p111 (2017-03-22 revision 58053) [x64-mingw32]
 0.90446  ruby 2.5.0dev (2017-10-23 trunk 60368) [x64-mingw32]


  10 Characters Print

 0.59375  ruby 1.9.3p551 (2014-11-13) [i386-mingw32]
 0.46878  ruby 2.0.0p648 (2015-12-16) [x64-mingw32]
 0.48440  ruby 2.1.9p490 (2016-03-30 revision 54437) [x64-mingw32]
 1.01562  ruby 2.2.6p396 (2016-11-15 revision 56800) [x64-mingw32]
 0.98440  ruby 2.3.3p222 (2016-11-21 revision 56859) [x64-mingw32]
 1.01565  ruby 2.4.1p111 (2017-03-22 revision 58053) [x64-mingw32]
 0.98707  ruby 2.5.0dev (2017-10-23 trunk 60368) [x64-mingw32]


2000 Characters Send

 0.56253  ruby 1.9.3p551 (2014-11-13) [i386-mingw32]
 1.75003  ruby 2.0.0p648 (2015-12-16) [x64-mingw32]
 1.03125  ruby 2.1.9p490 (2016-03-30 revision 54437) [x64-mingw32]
 1.01565  ruby 2.2.6p396 (2016-11-15 revision 56800) [x64-mingw32]
 1.03124  ruby 2.3.3p222 (2016-11-21 revision 56859) [x64-mingw32]
 1.00002  ruby 2.4.1p111 (2017-03-22 revision 58053) [x64-mingw32]
 0.95394  ruby 2.5.0dev (2017-10-23 trunk 60368) [x64-mingw32]


2000 Characters Print

 0.60941  ruby 1.9.3p551 (2014-11-13) [i386-mingw32]
 0.50001  ruby 2.0.0p648 (2015-12-16) [x64-mingw32]
 0.51566  ruby 2.1.9p490 (2016-03-30 revision 54437) [x64-mingw32]
 1.03125  ruby 2.2.6p396 (2016-11-15 revision 56800) [x64-mingw32]
 1.01562  ruby 2.3.3p222 (2016-11-21 revision 56859) [x64-mingw32]
 1.04689  ruby 2.4.1p111 (2017-03-22 revision 58053) [x64-mingw32]
 1.00382  ruby 2.5.0dev (2017-10-23 trunk 60368) [x64-mingw32]
Actions
Copy link
 #12 [ruby-core:115367]

Updated by JesseJohnson (Jesse Johnson) about 1 year ago

Can anyone replicate this on Ruby 3 or later?

Actions
Copy link
 #13 [ruby-core:115399]

Updated by cs96and (Alan Davies) about 1 year ago

JesseJohnson (Jesse Johnson) wrote in #note-12:

Can anyone replicate this on Ruby 3 or later?

Still poor performance in 3.1.3 and 3.2.2...

1.9.3 send()

$ ./ruby-1.9.3-p551-i386-mingw32/bin/ruby.exe --version
ruby 1.9.3p551 (2014-11-13) [i386-mingw32]

$ time ./ruby-1.9.3-p551-i386-mingw32/bin/ruby.exe d:/socketsendtest.rb

real    0m1.086s
user    0m0.000s
sys     0m0.000s

1.9.3 print()

$ time ./ruby-1.9.3-p551-i386-mingw32/bin/ruby.exe d:/socketsendtest.rb

real    0m1.108s
user    0m0.000s
sys     0m0.000s

3.1.3 send()

$ /c/tools/ruby31/bin/ruby --version
ruby 3.1.3p185 (2022-11-24 revision 1a6b16756e) [x64-mingw-ucrt]

$ time /c/tools/ruby31/bin/ruby d:/socketsendtest.rb

real    0m1.927s
user    0m0.000s
sys     0m0.015s

3.1.3 print()

$ time /c/tools/ruby31/bin/ruby d:/socketsendtest.rb

real    0m1.273s
user    0m0.000s
sys     0m0.015s

3.2.2 send()

$ ./rubyinstaller-3.2.2-1-x64/bin/ruby.exe --version
ruby 3.2.2 (2023-03-30 revision e51014f9c0) [x64-mingw-ucrt]

$ time ./rubyinstaller-3.2.2-1-x64/bin/ruby.exe d:/socketsendtest.rb

real    0m2.044s
user    0m0.000s
sys     0m0.000s

3.2.2 print()

$ time ./rubyinstaller-3.2.2-1-x64/bin/ruby.exe d:/socketsendtest.rb

real    0m1.338s
user    0m0.000s
sys     0m0.000s
Actions
Copy link
 #14 [ruby-core:115401]

Updated by k0kubun (Takashi Kokubun) about 1 year ago

Just in case, could you measure the time spent on the loop instead of a whole Ruby command? The prelude script sometimes takes a lot of time, the performance varies across different versions, and time command would benchmark that as well. You can just call Time.new before and after the loop, subtract them, and report the result for each version.

Actions
Copy link
 #15 [ruby-core:115403]

Updated by cs96and (Alan Davies) about 1 year ago

k0kubun (Takashi Kokubun) wrote in #note-14:

Just in case, could you measure the time spent on the loop instead of a whole Ruby command? The prelude script sometimes takes a lot of time, the performance varies across different versions, and time command would benchmark that as well. You can just call Time.new before and after the loop, subtract them, and report the result for each version.

I also increased the loop by a factor of 10 (to 1,000,000) so it runs for longer. Times are in seconds...

1.9.3 send:

ruby-1.9.3\bin\ruby.exe socketsendtest.rb
10.495193

1.9.3 print:

ruby-1.9.3\bin\ruby.exe socketsendtest.rb
10.384035

3.2.2 send

ruby-3.2.2\bin\ruby.exe socketsendtest.rb
17.3447397

3.2.2 print

ruby-3.2.2\bin\ruby.exe socketsendtest.rb
9.8053804

Out of interest I ran the code through the profile module as well...

1.9.3 send

ruby-1.9.3\bin\ruby.exe -rprofile socketsendtest.rb
19.520433
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 56.95     6.03      6.03  1000000     0.01     0.01  UDPSocket#send
 43.05    10.59      4.56        1  4561.00 10594.00  Integer#times
  0.00    10.59      0.00        1     0.00     0.00  UDPSocket#bind
  0.00    10.59      0.00       10     0.00     0.00  Class#inherited
  0.00    10.59      0.00       40     0.00     0.00  BasicObject#singleton_method_added
  0.00    10.59      0.00      104     0.00     0.00  Module#method_added
  0.00    10.59      0.00        2     0.00     0.00  Kernel.gem_original_require
  0.00    10.59      0.00        2     0.00     0.00  Kernel.require
  0.00    10.59      0.00        4     0.00     0.00  Module#private
  0.00    10.59      0.00        2     0.00     0.00  Module#attr_reader
  0.00    10.59      0.00        1     0.00     0.00  UDPSocket#initialize
  0.00    10.59      0.00        1     0.00     0.00  IO#new
  0.00    10.59      0.00        2     0.00     0.00  Hash#empty?
  0.00    10.59      0.00        1     0.00     0.00  UDPSocket#connect
  0.00    10.59      0.00        2     0.00     0.00  Time#initialize
  0.00    10.59      0.00        2     0.00     0.00  Class#new
  0.00    10.59      0.00        4     0.00     0.00  IO#set_encoding
  0.00    10.59      0.00        2     0.00     0.00  Gem.unresolved_deps
  0.00    10.59      0.00        1     0.00     0.00  Float#/
  0.00    10.59      0.00        1     0.00     0.00  Float#quo
  0.00    10.59      0.00        1     0.00     0.00  Time#-
  0.00    10.59      0.00        1     0.00     0.00  Float#to_s
  0.00    10.59      0.00        2     0.00     0.00  IO#write
  0.00    10.59      0.00        1     0.00     0.00  IO#puts
  0.00    10.59      0.00        1     0.00     0.00  Kernel.puts
  0.00    10.59      0.00        1     0.00 10594.00  #toplevel

1.9.3 print

ruby-1.9.3\bin\ruby.exe -rprofile socketsendtest.rb
25.818462
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 38.19     6.18      6.18  1000000     0.01     0.01  IO#print
 33.27    11.56      5.38  1000002     0.01     0.01  IO#write
 28.45    16.16      4.60        1  4600.00 16156.00  Integer#times
  0.09    16.17      0.01        2     7.50    15.00  Kernel.require
  0.00    16.17      0.00        1     0.00     0.00  UDPSocket#bind
  0.00    16.17      0.00      104     0.00     0.00  Module#method_added
  0.00    16.17      0.00        2     0.00     7.50  Kernel.gem_original_require
  0.00    16.17      0.00        4     0.00     0.00  IO#set_encoding
  0.00    16.17      0.00        4     0.00     0.00  Module#private
  0.00    16.17      0.00        2     0.00     0.00  Module#attr_reader
  0.00    16.17      0.00        1     0.00     0.00  UDPSocket#initialize
  0.00    16.17      0.00        1     0.00     0.00  IO#new
  0.00    16.17      0.00       40     0.00     0.00  BasicObject#singleton_method_added
  0.00    16.17      0.00        1     0.00     0.00  UDPSocket#connect
  0.00    16.17      0.00        2     0.00     0.00  Time#initialize
  0.00    16.17      0.00        2     0.00     0.00  Class#new
  0.00    16.17      0.00       10     0.00     0.00  Class#inherited
  0.00    16.17      0.00        2     0.00     0.00  Hash#empty?
  0.00    16.17      0.00        2     0.00     0.00  Gem.unresolved_deps
  0.00    16.17      0.00        1     0.00     0.00  Float#/
  0.00    16.17      0.00        1     0.00     0.00  Float#quo
  0.00    16.17      0.00        1     0.00     0.00  Time#-
  0.00    16.17      0.00        1     0.00     0.00  Float#to_s
  0.00    16.17      0.00        1     0.00     0.00  IO#puts
  0.00    16.17      0.00        1     0.00     0.00  Kernel.puts
  0.00    16.17      0.00        1     0.00 16171.00  #toplevel

3.2.2 send

ruby-3.2.2\bin\ruby.exe -rprofile socketsendtest.rb
32.9209883
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 39.03     7.72      7.72  1000000     0.01     0.02  nil#
 38.17    15.27      7.55  1000000     0.01     0.01  UDPSocket#send
 22.72    19.77      4.50        1  4495.00 19766.00  Integer#times
  0.08    19.78      0.02        4     4.00    16.00  Kernel#require
  0.00    19.78      0.00        2     0.00     0.00  Kernel#respond_to?
  0.00    19.78      0.00        2     0.00     0.00  Hash#[]
  0.00    19.78      0.00        2     0.00     0.00  Gem.find_unresolved_default_spec
  0.00    19.78      0.00        2     0.00     0.00  Gem::Specification.unresolved_deps
  0.00    19.78      0.00        2     0.00     0.00  Hash#empty?
  0.00    19.78      0.00        2     0.00     0.00  Monitor#exit
  0.00    19.78      0.00      378     0.00     0.00  Module#const_added
  0.00    19.78      0.00       13     0.00     0.00  Class#inherited
  0.00    19.78      0.00       50     0.00     0.00  BasicObject#singleton_method_added
  0.00    19.78      0.00      141     0.00     0.00  Module#method_added
  0.00    19.78      0.00        2     0.00     0.00  Monitor#enter
  0.00    19.78      0.00        1     0.00     0.00  Module#method_defined?
  0.00    19.78      0.00        1     0.00     0.00  Module#protected
  0.00    19.78      0.00        1     0.00     0.00  String#=~
  0.00    19.78      0.00        3     0.00     0.00  Module#private
  0.00    19.78      0.00        2     0.00     0.00  Module#attr_reader
  0.00    19.78      0.00        1     0.00     0.00  UDPSocket#initialize
  0.00    19.78      0.00        1     0.00     0.00  IO.new
  0.00    19.78      0.00        1     0.00     0.00  UDPSocket#bind
  0.00    19.78      0.00        1     0.00     0.00  UDPSocket#connect
  0.00    19.78      0.00        2     0.00     0.00  Time#initialize
  0.00    19.78      0.00        2     0.00     0.00  Class#new
  0.00    19.78      0.00        2     0.00     0.00  Gem.discover_gems_on_require
  0.00    19.78      0.00        4     0.00     0.00  IO#set_encoding
  0.00    19.78      0.00        1     0.00     0.00  TracePoint#enable
  0.00    19.78      0.00        1     0.00     0.00  Float#/
  0.00    19.78      0.00        1     0.00     0.00  Float#fdiv
  0.00    19.78      0.00        1     0.00     0.00  Time#-
  0.00    19.78      0.00        1     0.00     0.00  Float#to_s
  0.00    19.78      0.00        1     0.00     0.00  IO#write
  0.00    19.78      0.00        1     0.00     0.00  IO#puts
  0.00    19.78      0.00        1     0.00     0.00  Kernel#puts
  0.00    19.78      0.00        1     0.00     0.00  TracePoint#disable
  0.00    19.78      0.00        1     0.00 19782.00  #toplevel

3.2.2 print

ruby-3.2.2\bin\ruby.exe -rprofile socketsendtest.rb
29.3270973
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 33.07     6.50      6.50  1000000     0.01     0.01  IO#print
 27.12    11.84      5.34  1000000     0.01     0.02  nil#
 21.52    16.08      4.23        1  4234.00 19672.00  Integer#times
 18.28    19.67      3.60  1000001     0.00     0.00  IO#write
  0.00    19.67      0.00        2     0.00     0.00  Kernel#respond_to?
  0.00    19.67      0.00        2     0.00     0.00  Hash#[]
  0.00    19.67      0.00        2     0.00     0.00  Gem.find_unresolved_default_spec
  0.00    19.67      0.00        2     0.00     0.00  Gem::Specification.unresolved_deps
  0.00    19.67      0.00        2     0.00     0.00  Hash#empty?
  0.00    19.67      0.00        2     0.00     0.00  Monitor#exit
  0.00    19.67      0.00      378     0.00     0.00  Module#const_added
  0.00    19.67      0.00       13     0.00     0.00  Class#inherited
  0.00    19.67      0.00       50     0.00     0.00  BasicObject#singleton_method_added
  0.00    19.67      0.00      141     0.00     0.00  Module#method_added
  0.00    19.67      0.00        2     0.00     0.00  Gem.discover_gems_on_require
  0.00    19.67      0.00        1     0.00     0.00  Module#method_defined?
  0.00    19.67      0.00        1     0.00     0.00  Module#protected
  0.00    19.67      0.00        1     0.00     0.00  String#=~
  0.00    19.67      0.00        3     0.00     0.00  Module#private
  0.00    19.67      0.00        2     0.00     0.00  Module#attr_reader
  0.00    19.67      0.00        1     0.00     0.00  UDPSocket#initialize
  0.00    19.67      0.00        1     0.00     0.00  IO.new
  0.00    19.67      0.00        1     0.00     0.00  UDPSocket#bind
  0.00    19.67      0.00        1     0.00     0.00  UDPSocket#connect
  0.00    19.67      0.00        2     0.00     0.00  Time#initialize
  0.00    19.67      0.00        2     0.00     0.00  Class#new
  0.00    19.67      0.00        2     0.00     0.00  Monitor#enter
  0.00    19.67      0.00        4     0.00     0.00  IO#set_encoding
  0.00    19.67      0.00        4     0.00     0.00  Kernel#require
  0.00    19.67      0.00        1     0.00     0.00  TracePoint#enable
  0.00    19.67      0.00        1     0.00     0.00  Float#/
  0.00    19.67      0.00        1     0.00     0.00  Float#fdiv
  0.00    19.67      0.00        1     0.00     0.00  Time#-
  0.00    19.67      0.00        1     0.00     0.00  Float#to_s
  0.00    19.67      0.00        1     0.00     0.00  IO#puts
  0.00    19.67      0.00        1     0.00     0.00  Kernel#puts
  0.00    19.67      0.00        1     0.00     0.00  TracePoint#disable
  0.00    19.67      0.00        1     0.00 19672.00  #toplevel

3.2.2 seems to be spending a fair amount of time in a function called nil#. Though the 3.2.2 print() version does as well, but doesn't suffer the slowdown.

Actions
Copy link

Also available in: Atom PDF

Like0
Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0