Openfire 3.7 slow startup

I’m currently running 3.6.4 in production and testing a 3.7.0 installation with copy of 3.6.4 database (Using Oracle backend - 3.6.4 is just a regular 11g database, 3.7.0 is 11g on RAC). I’ve noticed that I can stop/start my 3.6.4 instance pretty quickly and it’s back up and running within around 10s:

2011.03.31 20:12:43 Openfire stopped

2011.03.31 20:12:43 Server halted

2011.03.31 20:12:45 Publish-Subscribe domain: pubsub.xxxx.com

2011.03.31 20:12:45 Multi User Chat domain: conference.xxxx.com

2011.03.31 20:12:46 Openfire 3.6.4 [Mar 31, 2011 8:12:46 PM]

2011.03.31 20:12:47 Admin console listening at:

http://xxxxx.com:9090

https://xxxx.com:9091

2011.03.31 20:12:48 Started server (unencrypted) socket on port: 5269

2011.03.31 20:12:48 Started multiplexer (unencrypted) socket on port: 5262

2011.03.31 20:12:48 Started plain (unencrypted) socket on port: 5222

2011.03.31 20:12:48 Started SSL (encrypted) socket on port: 5223

My 3.7 instance takes over a minute to start up, sometimes closer to 90s. It also seems to ignore my log.debug.enabled=true paramter in the openfire.xml file - nothing is logged to debug.log. I can go into the admin console and turn on debug, but next time i cycle it gets turned off. Obviously it would be helpful to get debug logs for immediatly after it starts to come up.

2011.03.31 20:13:44 Openfire stopped

2011.03.31 20:13:44 Server halted

2011.03.31 20:14:33 Publish-Subscribe domain: pubsub.xxxx.com

2011.03.31 20:14:33 Multi User Chat domain: conference.xxxx.com

2011.03.31 20:14:33 Openfire 3.7.0 [Mar 31, 2011 8:14:33 PM]

2011.03.31 20:14:34 Admin console listening at https://xxxxx.com:9091

2011.03.31 20:14:35 Started multiplexer (unencrypted) socket on port: 5262

2011.03.31 20:14:35 Started plain (unencrypted) socket on port: 5222

I caused a javacore on the 3.7.0 instance during startup (but before it logs anything to info.log) and the only thing interesting is this - I’m not a java expert, so I’m not sure how to interpret it.

“Prototyper” daemon prio=10 tid=0xdd9a9400 nid=0x3a2d waiting for monitor entry

[0xdeb7d000]

java.lang.Thread.State: BLOCKED (on object monitor)

at java.io.BufferedInputStream.read(Unknown Source)

  • waiting to lock <0xeee35430> (a java.io.BufferedInputStream)

at sun.security.provider.SeedGenerator$URLSeedGenerator.getSeedByte(Unkn

own Source)

at sun.security.provider.SeedGenerator.getSeedBytes(Unknown Source)

at sun.security.provider.SeedGenerator.generateSeed(Unknown Source)

at sun.security.provider.SecureRandom.engineGenerateSeed(Unknown Source)

at sun.security.provider.SecureRandom.engineNextBytes(Unknown Source)

  • locked <0xeee350a8> (a sun.security.provider.SecureRandom)

at java.security.SecureRandom.nextBytes(Unknown Source)

  • locked <0xeee35310> (a java.security.SecureRandom)

at oracle.security.o5logon.O5LoginClientHelper.generateOAuthResponse(Unk

nown Source)

at oracle.security.o5logon.O5LoginClientHelper.generateOAuthResponse(Unk

nown Source)

at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.ja

va:655)

at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:359)

at oracle.jdbc.driver.PhysicalConnection.(PhysicalConnection.java:

at oracle.jdbc.driver.T4CConnection.(T4CConnection.java:221)

at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtensio

n.java:32)

at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:503)

at java.sql.DriverManager.getConnection(Unknown Source)

at java.sql.DriverManager.getConnection(Unknown Source)

at org.logicalcobwebs.proxool.DefaultConnectionBuilder.buildConnection(D

efaultConnectionBuilder.java:39)

at org.logicalcobwebs.proxool.Prototyper.buildConnection(Prototyper.java

:159)

at org.logicalcobwebs.proxool.Prototyper.sweep(Prototyper.java:102)

at org.logicalcobwebs.proxool.PrototyperThread.run(PrototyperThread.java

:44)

Did further troubleshooting this morning, including:

  • Reverting to the 11.1 thin client
  • Connecting to a non-RAC database
  • Starting over with a copy of my 3.6.4 database and starting 3.7.0 to upgrade it from v20 to v21

None of these had an impact on start up time. I rsynced /opt/openfire over from my new environment (RHEL6 64bit) to the backup box for my current production install (RHEL4.8 64bit). Openfire starts up in <5s on the RHEL4 environment - Same openfire.xml, same database, same ojdbc.jar. RHEL6 statup is typically 45s, although in one instance it was closer to 180s.

Anyone else running Openfire on RHEL6?

Okay, finally figured this out… RHEL6 seems to generate less ‘entropy’ than RHEL4/5.

A RHEL6 box:

[root@rhesproddns02 ~]# cat /proc/sys/kernel/random/entropy_avail

170

A RHEL4 box:

[root@rhtsutility02 ~]# cat /proc/sys/kernel/random/entropy_avail

4032

By using rngd, the amount of entropy can be increased:

rngd -r /dev/urandom -o /dev/random -f -t 1

Once rngd is running, Openfire starts up in around 3s, rather than >60s. I’m not convinced running rngd is the appropriate solution/workaround, but it does seem to resolve the issue.

**
**