Weblogic is slow to start (11mins) under VM (VirtualBox and VMware)

Question

(SOLVED! BY FAKING SYSTEM RANDOM GENERATOR, SEE BELOW)

I'm setting up a VM image for my dev/build team. Inside that VM a Weblogic domain should be running. I use Ububtu server distro, WLS 9.2MP3 + ALSB.

Everything works OK, quite fast, but at the start time the WLS stops twice for a measurable amounts of time. Two stops in total amount to about 10 minutes delay. For tasks where deployment requires server restart it's very annoying. :-(

Sleeping time is not constant, sometimes the server starts very fast, sometimes so-so, sometimes 10 minutes or more.

Interesting that if I press Enter while looking at the stopped server, it wakes up much faster, sometimes after a few seconds. WLST (Weblogic Jython shell) is also hanging for quite a time when executed in VM. It doesn't react to Enter though.

Here must be some developers who run WLS with a VM. I wonder if others have the same problem? Was someone able to solve it?

Here's the server output (just for a case):

Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_12-b04)
Java HotSpot(TM) Client VM (build 1.5.0_12-b04, mixed mode)
Starting WLS with line:
/shared2/beahome/jdk150_12/bin/java -client   -Xmx256m  -XX:MaxPermSize=128m  -Xverify:none  -da -Dplatform.home=/shared2/beahome/weblogic92
 -Dwls.home=/shared2/beahome/weblogic92/server -Dwli.home=/shared2/beahome/weblogic92/integration  -Dweblogic.management.discover=true  -Dwl
w.iterativeDev= -Dwlw.testConsole= -Dwlw.logErrorsToConsole= -Dweblogic.ext.dirs=/shared2/beahome/patch_weblogic923/profiles/default/sysext_
manifest_classpath -Dweblogic.management.username=admin -Dweblogic.management.password=wlsadmin -Dweblogic.Name=LOGMGR-admin -Djava.security
.policy=/shared2/beahome/weblogic92/server/lib/weblogic.policy   weblogic.Server
<1-Apr-2010 12:47:22 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000395> <Following extensions directory contents added to the end
of the classpath:
/shared2/beahome/weblogic92/platform/lib/p13n/p13n-schemas.jar:/shared2/beahome/weblogic92/platform/lib/p13n/p13n_common.jar:/shared2/beahom
e/weblogic92/platform/lib/p13n/p13n_system.jar:/shared2/beahome/weblogic92/platform/lib/wlp/netuix_common.jar:/shared2/beahome/weblogic92/pl
atform/lib/wlp/netuix_schemas.jar:/shared2/beahome/weblogic92/platform/lib/wlp/netuix_system.jar:/shared2/beahome/weblogic92/platform/lib/wl
p/wsrp-common.jar>
<1-Apr-2010 12:47:22 o'clock PM GMT-05:00> <Info> <WebLogicServer> <BEA-000377> <Starting WebLogic Server with Java HotSpot(TM) Client VM Ve
rsion 1.5.0_12-b04 from Sun Microsystems Inc.>
<1-Apr-2010 12:47:23 o'clock PM GMT-05:00> <Info> <Management> <BEA-141107> <Version: WebLogic Server 9.2 MP3  Mon Mar 10 08:28:41 EDT 2008
1096261 >
<1-Apr-2010 12:47:25 o'clock PM GMT-05:00> <Info> <WebLogicServer> <BEA-000215> <Loaded License : /shared2/beahome/license.bea>
<1-Apr-2010 12:47:25 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to STARTING>
<1-Apr-2010 12:47:25 o'clock PM GMT-05:00> <Info> <WorkManager> <BEA-002900> <Initializing self-tuning thread pool>
<1-Apr-2010 12:47:25 o'clock PM GMT-05:00> <Notice> <Log Management> <BEA-170019> <The server log file /shared2/wldomains/beaadmd/LOGMGR/ser
vers/LOGMGR-admin/logs/LOGMGR-admin.log is opened. All server side log events will be written to this file.>

Here we have the first delay, up to 5 mins...

<1-Apr-2010 12:53:21 o'clock PM GMT-05:00> <Notice> <Security> <BEA-090082> <Security initializing using security realm myrealm.>
<1-Apr-2010 12:53:24 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to STANDBY>
<1-Apr-2010 12:53:24 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to STARTING>
<1-Apr-2010 12:53:25 o'clock PM GMT-05:00> <Notice> <Log Management> <BEA-170027> <The server initialized the domain log broadcaster success
fully. Log messages will now be broadcasted to the domain log.>
<1-Apr-2010 12:53:25 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to ADMIN>
<1-Apr-2010 12:53:25 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to RESUMING>
<1-Apr-2010 12:53:28 o'clock PM GMT-05:00> <Notice> <Security> <BEA-090171> <Loading the identity certificate and private key stored under t
he alias adminuialias from the jks keystore file /shared2/wldomains/beaadmd/LOGMGR/CustomIdentity.jks.>

And here is the second, again up to 5 mins.

<1-Apr-2010 12:58:56 o'clock PM GMT-05:00> <Notice> <Security> <BEA-090169> <Loading trusted certificates from the jks keystore file /shared
2/wldomains/beaadmd/LOGMGR/CustomTrust.jks.>
<1-Apr-2010 12:58:57 o'clock PM GMT-05:00> <Notice> <Server> <BEA-002613> <Channel "DefaultSecure" is now listening on 192.168.56.102:7002 f
or protocols iiops, t3s, ldaps, https.>
<1-Apr-2010 12:58:57 o'clock PM GMT-05:00> <Notice> <Server> <BEA-002613> <Channel "Default" is now listening on 192.168.56.102:8012 for pro
tocols iiop, t3, ldap, http.>
<1-Apr-2010 12:58:57 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000331> <Started WebLogic Admin Server "LOGMGR-admin" for domain "
LOGMGR" running in Development Mode>
<1-Apr-2010 12:58:57 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to RUNNING>
<1-Apr-2010 12:58:57 o'clock PM GMT-05:00> <Notice> <WebLogicServer> <BEA-000360> <Server started in RUNNING mode>

UPDATE

I think I've got the track: it must be the randon seed initialization. That may explain why generating keyboard events release the server. I've made the thread dump, and one thread is in runnable state, but waiting:

"[STANDBY] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=1 tid=0x0a7b06e8 nid=0xeda runnable [0x728a500
0..0x728a6d80]
        at java.io.FileInputStream.readBytes(Native Method)
        at java.io.FileInputStream.read(FileInputStream.java:194)
        at sun.security.provider.NativePRNG$RandomIO.readFully(NativePRNG.java:185)
        at sun.security.provider.NativePRNG$RandomIO.implGenerateSeed(NativePRNG.java:202)
        - locked <0x7d928c78> (a java.lang.Object)
        at sun.security.provider.NativePRNG$RandomIO.access$300(NativePRNG.java:108)
        at sun.security.provider.NativePRNG.engineGenerateSeed(NativePRNG.java:102)
        at java.security.SecureRandom.generateSeed(SecureRandom.java:475)
        at weblogic.security.AbstractRandomData.ensureInittedAndSeeded(AbstractRandomData.java:83)

Answer 1

SOLVED

Weblogic uses SecureRandom to init security subsystem. SecureRandom by default uses /dev/urandom device. For some reason, reading this device under VM comes to halt quite often. Generating console events helps to create more randomness, and release the WLS.

For the test purposes I have changed jre/lib/security/java.security file:

securerandom.source=file:/tmp/big.random.file

Weblogic now starts in 15 seconds.

Since we do not test any security stuff in our VMs, the repeating seed is totally alright for us.

Answer 2

In case you have enterprise standard app servers without privileges to change your binaries you can add a JVM flag to overwrite wich random generator should be used. E.g.:

-Djava.security.egd=file:/dev/./urandom

That way you don't have to change any system settings.

Answer 3

Oracle has since created a Metalink note related to this The FMW Configuration Wizard Is Very Slow On Linux Virtual Environments. The Startup Of WLS Servers Is Also Very Slow. [ID 1344974.1]

...

Solution 1 1) Download and install the following rpm: rng-utils-2.0-1.14.1.fc6.x86_64.rpm . Contact your vendor for download details. 2) Startup the random generator as follows: rngd -r /dev/urandom -o /dev/random -t 1

By default there seems to be a dependency on /dev/random on Linux which blocks until enough randomness is generated. Virtual servers with no mouse and keyboard attached can block significantly. In the command above input is taken from the unblocking /dev/urandom so the wait for randomness does not become an application bottleneck.