I am trying to debug a few slow responses served by an app deployed on Tomcat.
Right now I am focussing on SecureRandom and /dev/random (some of the other probable causes have been investigated and ruled out).
The pattern is as follows:
- The first call takes exactly 30.0xy seconds after Tomcat restart (even if the request arrives 4 minutes after the Startup)
- Later, some calls take exactly 15.0pq seconds (there was no specific pattern that I could establish, pq being the time approximate time taken in TP99)
The service call involves encryption and decryption (AES/ECB/PKCS5Padding).
Is it possible that SecureRandom init/repopulating is leading to this?
(Although, there is a log written in catalina.log that says "Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [28,760] milliseconds.")
Also, in order to check whether /dev/random or /dev/urandom is being used, I used the test from this question. To my surprise, I didn't see reads from either of them unlike the way it happens in the linked question.
These are the last few lines from the strace log:
3561 lstat("/usr/lib/jvm/java-1.6.0-openjdk-1.6.0.0.x86_64/jre/lib/jsse.jar", {st_mode=S_IFREG|0644, st_size=258525, ...}) = 0
3561 open("/usr/lib/jvm/java-1.6.0-openjdk-1.6.0.0.x86_64/jre/lib/jsse.jar", O_RDONLY) = 6
3561 stat("/dev/random", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 8), ...}) = 0
3561 stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
3561 open("/dev/random", O_RDONLY) = 7
3561 open("/dev/urandom", O_RDONLY) = 8
3561 unlink("/tmp/hsperfdata_xxxx/3560") = 0
What is then being used for seeding SecureRandom?
fyi, java -version
java version "1.6.0_32"
OpenJDK Runtime Environment (IcedTea6 1.13.4) (rhel-7.1.13.4.el6_5-x86_64)
OpenJDK 64-Bit Server VM (build 23.25-b01, mixed mode)
I could not check your OpenJDK concrete version, but I could check jdk6-b33.
SecureRandom uses SeedGenerator to get the seed bytes
SeedGenerator gets the
seedSource(String) from SunEntriesSunEntriestries to get the source from the system propertyjava.security.egdfirst, if is not found then tries to get the propertysecurerandom.sourcefrom thejava.securityproperties file, if the property is not found returns a blank string.the
SeedGeneratorcheck this value to initialize the instanceif the source is
or
uses the
NativeSeedGenerator, on Windows tries to use the nativeCryptoAPIon Linux the class simply extends theSeedGenerator.URLSeedGeneratorand call to the superclass constructor who loads
/dev/randomby defaultso, OpenJDK uses
/dev/randomby default until you do not set another value in the system propertyjava.security.egdor in the propertysecurerandom.sourceof security properties file.If you want to see the read results using
straceyou can change the command line and add thetrace=open,readexpressionthe you can see something like this (I did the test with Oracle JDK 6)
The Tomcat Wiki section for faster startup suggest using a non-blocking entropy source like /dev/urandom if you are experiencing delays during startup
More info: https://wiki.apache.org/tomcat/HowTo/FasterStartUp#Entropy_Source
Hope this helps.