apache procrun fails to start service

Question

EDIT

I am making use of the loaderDeamon interface to install and run a java app as a windows service. To do this, Apache's procrun service tool (same thing that gets installed with tomcat) handles the installation and execution of the service.

Recently when executing the service via the service manager, the service claims to be running, but does not respond. No log is written, and the client side of the app isn't able to communicate. This makes me think the service is not actually running.

I've attempted to launch the service via procrun by the //TS command as documented here: http://commons.apache.org/daemon/procrun.html, which hangs and hasn't started the service even if we wait up to 24 hours. The procrun itself generates a log that we've captured. The full log is included below. I have several questions about the log that I hope will clear up why the service doesn't start.

1. First, what does 'Java Worker thread finished... start with status=6' indicate on the termination of a thread?
2. Second, which threads are still executing when we get to the line 'Waiting for all threads to exit'?
3. Third, is there anything else in the log that stands out at potentially problematic when starting a service?

This service has executed successfully in the past, and recently failed after an upgrade to java version 1.7.5. I reverted back to java 1.7.3 with to effect, so I believe the jvm change is unrelated, though worth mentioning.

[2012-07-24 07:16:04] [debug] ( prunsrv.c:1644) Commons Daemon procrun log initialized
[2012-07-24 07:16:04] [info]  ( prunsrv.c:1648) Commons Daemon procrun (1.0.10.0 32-bit) started
[2012-07-24 07:16:04] [debug] ( prunsrv.c:559 ) Installing service...
[2012-07-24 07:16:04] [info]  ( prunsrv.c:595 ) Service CProgramFilesx86XpressfeedLoaderV5serviceLoaderEngine name XF Engine - C:\Program Files (x86)\Xpressfeed Loader V5 service\Loader
[2012-07-24 07:16:04] [debug] ( prunsrv.c:611 ) Setting service description The Xpressfeed V5 loader engine, used in headless mode to run load jobs in the background.
[2012-07-24 07:16:04] [info]  ( prunsrv.c:629 ) Service 'CProgramFilesx86XpressfeedLoaderV5serviceLoaderEngine' installed
[2012-07-24 07:16:04] [info]  ( prunsrv.c:1729) Commons Daemon procrun finished
[2012-07-24 07:16:13] [debug] ( prunsrv.c:1644) Commons Daemon procrun log initialized
[2012-07-24 07:16:13] [info]  ( prunsrv.c:1648) Commons Daemon procrun (1.0.10.0 32-bit) started
[2012-07-24 07:16:13] [info]  ( prunsrv.c:1545) Debugging 'CProgramFilesx86XpressfeedLoaderV5serviceLoaderEngine' service...
[2012-07-24 07:16:13] [debug] ( prunsrv.c:1345) Inside ServiceMain...
[2012-07-24 07:16:13] [info]  ( prunsrv.c:1089) Starting service...
[2012-07-24 07:16:13] [debug] ( javajni.c:206 ) loading jvm 'C:\Program Files (x86)\Java\jre7\bin\client\jvm.dll'
[2012-07-24 07:16:13] [debug] ( javajni.c:660 ) Jvm Option[0] -Djava.net.preferIPv4Stack=true
[2012-07-24 07:16:13] [debug] ( javajni.c:660 ) Jvm Option[1] -Djava.class.path=.;conf;dist\XpressfeedLoader.jar;lib\antlr-2.7.6.jar;lib\apache-log4j-extras-1.1.jar;lib\asm.jar;lib\auth\IA64\sqljdbc_auth.dll;lib\auth\x64\sqljdbc_auth.dll;lib\auth\x86\sqljdbc_auth.dll;lib\c3p0-0.9.1.2.jar;lib\cglib-2.2.jar;lib\commons-codec-1.4.jar;lib\commons-collections-3.1.jar;lib\commons-daemon-1.0.3.jar;lib\commons-dbcp-1.4.jar;lib\commons-lang-2.5.jar;lib\commons-logging-1.0.4.jar;lib\commons-pool-1.5.5.jar;lib\derby-10.6.2.1.jar;lib\dom4j-1.6.1.jar;lib\edtftpj-pro.jar;lib\freemarker.jar;lib\gui\jcommon-1.0.16.jar;lib\gui\jfreechart-1.0.13.jar;lib\hibernate-c3p0-3.5.2-Final.jar;lib\hibernate-tools.jar;lib\hibernate3.jar;lib\hsqldb.jar;lib\IAClasses.zip;lib\jargs.jar;lib\javassist.jar;lib\jaxen-1.1.1.jar;lib\jta.jar;lib\jtidy-r8-20060801.jar;lib\jung\collections-generic-4.01.jar;lib\jung\colt-1.2.0.jar;lib\jung\concurrent-1.3.4.jar;lib\jung\j3d-core-1.3.1.jar;lib\jung\jung-3d-2.0.1.jar;lib\jung\jung-algorithms-2.0.1.jar;lib\jung\jung-api-2.0.1.jar;lib\jung\jung-graph-i
[2012-07-24 07:16:13] [debug] ( javajni.c:660 ) Jvm Option[2] -Xms256m
[2012-07-24 07:16:13] [debug] ( javajni.c:660 ) Jvm Option[3] -Xmx1024m
[2012-07-24 07:16:13] [debug] ( javajni.c:880 ) DLL search path set to 'C:\PROGRA~2\XPRESS~2\jre\bin'
[2012-07-24 07:16:13] [debug] ( javajni.c:897 ) Java Worker thread started com/capitaliq/loader/loaderservice/LoaderService:start
[2012-07-24 07:16:13] [debug] ( javajni.c:914 ) Java Worker thread finished com/capitaliq/loader/loaderservice/LoaderService:start with status=6
[2012-07-24 07:16:14] [debug] ( prunsrv.c:1148) Java started com/capitaliq/loader/loaderservice/LoaderService
[2012-07-24 07:16:14] [info]  ( prunsrv.c:1244) Service started in 1160 ms.
[2012-07-24 07:16:14] [debug] ( prunsrv.c:1496) Waiting for worker to finish...
[2012-07-24 07:16:14] [debug] ( prunsrv.c:1501) Worker finished.
[2012-07-24 07:16:14] [debug] ( prunsrv.c:1524) Waiting for all threads to exit

Steps I've taken with no effect:

1. Running the service at the console with debug
2. Specifying java SE versions 1.7.5, 1.7.3
3. Just using the default jvm 1.6.30, not specifying it
4. Extensive google work

Any help or ideas appreciated! Thanks!

Answer 1

After heavy use of the time-honed debugging strategy of commenting out stuff and running until it works, I eventually narrowed the problem down a recent upgrade of our log4j jars. We were running apache's log4j with the following versions:

• apache-log4j-extras-1.0.jar
• log4j-1.2.16.jar
• slf4j-api-1.5.8.jar
• slf4j-log4j12-1.5.8.jar

We upgraded to the following, which caused the problem:

• apache-log4j-extras-1.1.jar
• log4j-1.2.17.jar
• slf4j-api-1.6.6.jar
• slf4j-log4j12-1.6.6.jar

After reverting back to the original jar files, the service was able to initialize and run without hanging.

Unfortunately, there was no stack or helpful error produced by the procrun logs (other than what I posted in the question), so I am unable to determine why log4j would conflict with initialization the service. If anyone else happens to know, I'm all ears - we will most likely be sticking with the older version of the jars until the unintended interaction is understood.

Answer 2

Recently, I had to try to get procrun to run my service as well. I found out after hours of trying to understand the issue that setting the --StdOutput and --StdError redirect parameters to auto. The stderr log gets generated in the --LogPath and contains the stack traces and other startup issues which cannot be seen in the standard Log file.