Project

General

Profile

Bug #14716

SecureRandom throwing an error in Ruby 2.5.1

Added by snehavas (sneha vasanth) about 1 year ago. Updated 3 months ago.

Status:
Open
Priority:
Normal
Assignee:
-
Target version:
-
[ruby-core:86709]

Description

Hi,

We recently upgraded from ruby 2.3.6 to 2.5.1.
We use SecureRandom.uuid to generate a random number for our session.
Post the upgrade we have been getting the following error intermittently

app error: failed to get urandom (RuntimeError)
E, [2018-04-27T04:55:08.741859 #16550] ERROR -- : /usr/lib/ruby/2.5.0/securerandom.rb:99:in `urandom'
E, [2018-04-27T04:55:08.741898 #16550] ERROR -- : /usr/lib/ruby/2.5.0/securerandom.rb:99:in `gen_random_urandom'
E, [2018-04-27T04:55:08.741932 #16550] ERROR -- : /usr/lib/ruby/2.5.0/securerandom.rb:129:in `random_bytes'
E, [2018-04-27T04:55:08.741965 #16550] ERROR -- : /usr/lib/ruby/2.5.0/securerandom.rb:219:in `uuid'
E, [2018-04-27T04:55:08.741997 #16550] ERROR -- : /usr/share/nginx/frontend/app/utilities/log.rb:74:in `create_session_info'
E, [2018-04-27T04:55:08.742036 #16550] ERROR -- : /usr/share/nginx/frontend/app/utilities/log.rb:11:in `context'

We understand that there was a change in ruby 2.5.1 where we now look at OS sources as the first point of contact to generate random numbers as opposed to OpenSSL.
Any idea why this could be happening?


Related issues

Related to Ruby trunk - Bug #9569: SecureRandom should try /dev/urandom firstClosedActions

History

#1

Updated by nobu (Nobuyoshi Nakada) about 1 year ago

  • Related to Bug #9569: SecureRandom should try /dev/urandom first added

Updated by nobu (Nobuyoshi Nakada) about 1 year ago

  • Status changed from Open to Feedback
  • Description updated (diff)

It depends on your OS.
What OS and the kernel version?

Updated by snehavas (sneha vasanth) about 1 year ago

We are using Ubuntu 14.04.5 LTS

Updated by snehavas (sneha vasanth) about 1 year ago

The Kernel version is 3.13.0-145-generic

Updated by naruse (Yui NARUSE) about 1 year ago

  • Backport changed from 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: UNKNOWN to 2.3: DONTNEED, 2.4: DONTNEED, 2.5: REQUIRED
  • Status changed from Feedback to Open

r57307 changed to use __NR_getrandom (kernel header) from SYS_getrandom (glibc header).
But __NR_getrandom is from v3.17.
It needs to check both __NR_getrandom and SYS_getrandom for compatibility.

Updated by naruse (Yui NARUSE) about 1 year ago

naruse (Yui NARUSE) wrote:

r57307 changed to use __NR_getrandom (kernel header) from SYS_getrandom (glibc header).
But __NR_getrandom is from v3.17.
It needs to check both __NR_getrandom and SYS_getrandom for compatibility.

genrandom(2) is introduced at v3.17.
On v3.13 kernel, it should fallback to /dev/urandom.
Maybe your environment doesn't have /dev/urandom?

Updated by shyouhei (Shyouhei Urabe) about 1 year ago

I can reproduce the situation using this Dockerfile https://github.com/shyouhei/docker-library/blob/master/%2314716/Dockerfile

The key point is to delete /dev/urandom from the image.

2.3.6 used to try openssl first, so if it had enough entropy that was okay. 2.5.1 prefers /dev/urandom (or getrandom(2), for newer kernels).

Updated by snehavas (sneha vasanth) about 1 year ago

We checked that by executing 'cat /dev/urandom' and we did see an output.
So dont think thats an issue.

We suspect that this issue occurs when there are many concurrent requests.

Updated by patbl (Patrick Brinich-Langlois) 10 months ago

We also got this error after upgrading to 2.5.1 (we had been on 2.4.2). We're also on a v3.13 kernel (3.13.0-24-generic). cat /dev/urandom produces output, and the errors are intermittent. Over the past day, failed to get urandom was our most common error, but there were several hours when we didn't get any such errors. So it seems possible that it occurs only when there are large numbers of requests, but I didn't try to see whether the request rate was correlated with the error rate.

Updated by patbl (Patrick Brinich-Langlois) 9 months ago

I worked around this problem by forcing SecureRandom to use the OpenSSL gem:

module SecureRandom
  if RUBY_VERSION == "2.5.1"
    class << self
      def gen_random(n)
        begin
          require 'openssl'
        rescue NoMethodError
          raise NotImplementedError, "No random device"
        else
          @rng_chooser.synchronize do
            class << self
              remove_method :gen_random
              alias gen_random gen_random_openssl
            end
          end
          return gen_random(n)
        end
      end
    end
  else
    raise "check whether this monkey patch is still correct"
  end
end

Updated by bruno (Bruno Sutic) 3 months ago

  • ruby -v changed from 2.5.1 to 2.5.3

Hi,
we're on "Ubuntu 14.04.5 LTS", kernel version "3.13.0-165".

2019-03-03T05:00:00.798Z 12950 TID-ors73fmw2 WARN: RuntimeError: failed to get urandom
2019-03-03T05:00:00.798Z 12950 TID-ors73fmw2 WARN: /usr/lib/ruby/2.5.0/securerandom.rb:99:in `urandom'
/usr/lib/ruby/2.5.0/securerandom.rb:99:in `gen_random_urandom'
/usr/lib/ruby/2.5.0/securerandom.rb:129:in `random_bytes'
/usr/lib/ruby/2.5.0/securerandom.rb:148:in `hex'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications/instrumenter.rb:50:in `unique_id'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications/instrumenter.rb:12:in `initialize'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications.rb:210:in `new'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications.rb:210:in `instrumenter_for'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications.rb:190:in `instrumenter'
/var/lib/gems/2.5.0/gems/activerecord-5.2.0/lib/active_record/querying.rb:44:in `find_by_sql'
/var/lib/gems/2.5.0/gems/activerecord-5.2.0/lib/active_record/statement_cache.rb:108:in `execute'
/var/lib/gems/2.5.0/gems/activerecord-5.2.0/lib/active_record/core.rb:175:in `find'
/home/deployer/mios/current/app/workers/lock_status_update_worker.rb:17:in `perform'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:185:in `execute_job'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:167:in `block (2 levels) in process'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
/var/lib/gems/2.5.0/gems/sentry-raven-2.7.4/lib/raven/integrations/sidekiq.rb:9:in `call'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/var/lib/gems/2.5.0/gems/sidekiq-pro-4.0.4/lib/sidekiq/batch/middleware.rb:29:in `call'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/var/lib/gems/2.5.0/gems/sidekiq-ent-1.7.2/lib/sidekiq-ent/unique.rb:143:in `call'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/var/lib/gems/2.5.0/gems/sidekiq-ent-1.7.2/lib/sidekiq-ent/limiter/middleware.rb:40:in `call'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/middleware/chain.rb:133:in `invoke'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:166:in `block in process'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:137:in `block (6 levels) in dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/job_retry.rb:108:in `local'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:136:in `block (5 levels) in dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/rails.rb:42:in `block in call'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/execution_wrapper.rb:87:in `wrap'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/reloader.rb:73:in `block in wrap'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/execution_wrapper.rb:87:in `wrap'
/var/lib/gems/2.5.0/gems/activesupport-5.2.0/lib/active_support/reloader.rb:72:in `wrap'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/rails.rb:41:in `call'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:132:in `block (4 levels) in dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:243:in `stats'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:127:in `block (3 levels) in dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/job_logger.rb:8:in `call'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:126:in `block (2 levels) in dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/job_retry.rb:73:in `global'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:125:in `block in dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/logging.rb:48:in `with_context'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/logging.rb:42:in `with_job_hash_context'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:124:in `dispatch'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:165:in `process'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:83:in `process_one'
/var/lib/gems/2.5.0/gems/sidekiq-5.2.3/lib/sidekiq/processor.rb:71:in `run'

We're using Ruby 2.5.3 and we can see this issue happening intermittently for one of our applications.

  • It doesn't happen for weeks, and then it suddenly starts happening.
  • The process that this happens in is "sidekiq", it runs background jobs.
  • Interestingly, our server runs our 4 other apps (ruby processes), and these apps don't get this error.
  • Restarting a process seems to fix the issue from happening.

Also available in: Atom PDF