Bug #2721: OpenSSL::Random.random_bytes(1) is very slow the first time on Windows

• Status: Third Party's Issue
• Assignee: -
• Target version: -
• ruby -v: ruby 1.8.6 (2009-08-04 patchlevel 383) [i386-mingw32]

[ghazel (Greg Hazel)]

=begin
This seems to be true across 1.8.6, 1.8.7 and even 1.9.1 compiled with either MSVC6 or mingw.

The first call to OpenSSL::Random.random_bytes for any number of bytes is very slow, proportional to something like the amount of code loaded already.

On my machine, the first call in a fresh irb session takes about 2 seconds.
Running something like this:

10000.times do |i|
eval("class SomeClass#{i}; end;")
end

increases the time for the first call to random_bytes to 5 seconds.

With a fresh Rails script/console, the first call takes about 30 seconds. Inside the first Rails request, it takes 80 seconds.

Calling the function as soon as possible allows me to spend only 2 seconds and not 80 later, but this seems like a very fixable thing.
=end

[naruse (Yui NARUSE)]

=begin
I can't reproduce this on FreeBSD/Ubuntu.
Anyone can reproduce on some platform?
=end

[ghazel (Greg Hazel)]

=begin
I'm on Windows 7. It does not happen on my CentOS box.
=end

[naruse (Yui NARUSE)]

• Category set to ext
• Status changed from Open to Assigned
• Assignee set to usa (Usaku NAKAMURA)

=begin

=end

[rogerdpack (Roger Pack)]

=begin
with mingw 1.9.x

Benchmark.realtime { OpenSSL::Random.random_bytes(1) }
=> 0.890625
Benchmark.realtime { OpenSSL::Random.random_bytes(1) }
=> 0.0

So a bit slow.

with
ruby 1.8.6 (2009-03-31 patchlevel 368) [i386-mingw32]

puts Benchmark.realtime { OpenSSL::Random.random_bytes(1) }
1.03125
=> nil
puts Benchmark.realtime { OpenSSL::Random.random_bytes(1) }
0.0

with
ruby 1.8.6 (2009-08-04 patchlevel 383) [i386-mingw32]

Benchmark.realtime { OpenSSL::Random.random_bytes(1) }
=> 0.53125
Benchmark.realtime { OpenSSL::Random.random_bytes(1) }
=> 0.0

this with XP Pro...
=end

[ghazel (Greg Hazel)]

=begin
A common stack:

ntdll.dll!RtlpNtMakeTemporaryKey+0x5866
ntdll.dll!RtlTimeToElapsedTimeFields+0x11922
ntdll.dll!RtlEnumProcessHeaps+0xac9
ntdll.dll!RtlEnumProcessHeaps+0xbc7
ntdll.dll!RtlValidateProcessHeaps+0x281
ntdll.dll!RtlTimeToElapsedTimeFields+0x12420
ntdll.dll!RtlQueryProcessHeapInformation+0x288
ntdll.dll!RtlTimeToElapsedTimeFields+0x6702
kernel32.dll!Heap32Next+0x4d
LIBEAY32.dll!RAND_poll+0x45f
msvcrt-ruby18.dll!rb_Array+0x2681
msvcrt-ruby18.dll!rb_funcall2+0x89

Another:

ntdll.dll!memset+0x45
ntdll.dll!RtlEnumProcessHeaps+0xbc7
ntdll.dll!RtlValidateProcessHeaps+0x281
ntdll.dll!RtlTimeToElapsedTimeFields+0x12420
ntdll.dll!RtlQueryProcessHeapInformation+0x288
ntdll.dll!RtlTimeToElapsedTimeFields+0x6702
kernel32.dll!Heap32Next+0x4d
LIBEAY32.dll!RAND_poll+0x45f
msvcrt-ruby18.dll!rb_Array+0x2681
msvcrt-ruby18.dll!rb_funcall2+0x89

Allocating the same amount of memory in a single string does not cause the same slow-down. So it looks like by defining classes many tiny malloc()s are done, which creates a large number of heap entries to walk.

=end

[nahi (Hiroshi Nakamura)]

=begin
Hi Greg,

Search 'openssl rand_poll heap32nex' and check if your environment
hits the problem or not. You might need to find a workaround.

Regards,
// NaHi

=end

[naruse (Yui NARUSE)]

• Status changed from Assigned to Feedback
• Assignee deleted (usa (Usaku NAKAMURA))

=begin

=end

[naruse (Yui NARUSE)]

• Status changed from Feedback to Rejected

=begin

=end

[naruse (Yui NARUSE)]

• Status changed from Rejected to Third Party's Issue

=begin

=end