Do you have entropy?

Posted by Henri Servomaa on 2016-02-16

We've been quite happy developing web sites in Clojure. We use the Leiningen toolchain: test locally, compile an uberjar and deploy it to a Java-provisioned server. But recently we started noticing very slow startup times. By slow, I mean up to 5 minutes before the web application would start responding. Moreover, the problem only appeared on production. Cold starting the same jar locally usually responded after about 10 seconds.

Debugging

Since uberjars are essentially Java, we needed to generate a thread dump to understand what was going on. There's a good utility, called jstack which can examine a running process. In our case the dump for a started server process looked like this

  Thread dump (kill -QUIT pid):
  Full thread dump OpenJDK 64-Bit Server VM (24.85-b03 mixed mode):

   "worker-2" daemon prio=10 tid=0x00007f8ea0007800 nid=0x5b88 in Object.wait() [0x00007f8ed233f000]
   java.lang.Thread.State: RUNNABLE
   at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:214)
   - locked <0x00000000f4a5b440> (a sun.security.provider.SecureRandom)
   at java.security.SecureRandom.nextBytes(SecureRandom.java:466)
   - locked <0x00000000f4a5b758> (a java.security.SecureRandom)
   at crypto.random\$bytes.invoke(random.clj:12)
   at crypto.random\$base64.invoke(random.clj:18)
   at ring.middleware.anti_forgery\$session_token.invoke(anti_forgery.clj:13)
   at ring.middleware.anti_forgery\$wrap_anti_forgery\$fn__2878.invoke(anti_forgery.clj:67)
  

The culprit is right there at the top: SecureRandom, the random number generation. However, we were so intent on finding fault in our application, that we initially skipped over it. Eventually, after trying various code hacks and looking at the umpteenth trace stopping at SecureRandom, the light-bulbs came on 💡💡!

Research

Now that we had a lead, it was easy to find this thread on stackoverflow. Essentially what was happening was that our server was running out of entropy. What is entropy? In this case it's random 'environmental' noise, generated by hardware events, such as mouse movements and key presses. These random bits of noise are stored in an 'entropy pool', which is used by /dev/random to generate random numbers. On headless servers (servers without local users) the entropy pool can dry up, causing /dev/random to block. We confirmed this by running

  ~\$ cat /proc/sys/kernel/random/entropy_avail
  88
  

The reason for low entropy has to do with how the pool is maintained in Linux. For more about that (fascinating) subject, see the man page. The Stackoverflow thread has several suggestions for mitigating the problem. Eventually we opted for Havege daemon, since it's readily packaged for Debian.

HAVEGE stands for HArdware Volatile Entropy Gathering and Expansion (homepage).

Here's the description from the Debian package

  Debian package:
  Description-en: Linux entropy source using the HAVEGE algorithm
  haveged is a userspace entropy daemon which is not dependent upon the
  standard mechanisms for harvesting randomness for the system entropy
  pool. This is important in systems with high entropy needs or limited
  user interaction (e.g. headless servers).

  haveged uses HAVEGE (HArdware Volatile Entropy Gathering and Expansion)
  to maintain a 1M pool of random bytes used to fill /dev/random
  whenever the supply of random bits in dev/random falls below the low
  water mark of the device.
  

This is a completely stand-alone daemon which works out of the box. It's memory footprint is also low by today's standards. On a Debian 8, 64bit server pmap reports a total of 12052K.

I can haz entropy!

After running haveged for a few minutes

  ~\$ cat /proc/sys/kernel/random/entropy_avail
  1801

Now, as expected, the Clojure web application startup was reduced to a few seconds. Yes!!

If you have any comments or suggestions, please tweet us.