conf/web.xml gets truncated

[bwallis42]

I'm running JBoss 3.2.3 on gentoo linux (kernel 2.6.7, libc 3.3.2) with jdk 1.4.2_05.

When I startup the jboss server it starts OK but then when starts up tomcat (log extract below) it gets a parse error and fails to deploy any of the web apps. The parse error is due to the default web.xml (in conf) being empty. But it was OK before I started jboss. Watching the conf directory you can see it is truncated about 10 seconds after the server starts (about 1/3rd of the startup time).

If I change the protection on the web.xml file so it is not writable then everything starts up OK, no error at all.

My JBoss configuration is not quite out of the box, the server configuration is a little modified for our production environment, but it is pretty close the original.

If I start an out of the box JBoss 3.2.3 system I notice that the web.xml last modified time is changed to the current time so someone is opening the file for write somewhere.

brian wallis...

---------------------------------------

2004-08-05 15:24:22,962 INFO [STDOUT] Apache Tomcat/4.1.29
2004-08-05 15:24:23,287 INFO [org.apache.coyote.http11.Http11Protocol] Initializing Coyote HTTP/1.1 on port 19201
2004-08-05 15:24:23,288 INFO [org.jboss.web.localhost.Engine] CoyoteConnector Coyote can't register jmx for protocol
2004-08-05 15:24:23,487 INFO [org.apache.coyote.http11.Http11Protocol] Starting Coyote HTTP/1.1 on port 19201
2004-08-05 15:24:23,552 INFO [org.jboss.web.localhost.Engine] CoyoteConnector Coyote can't register jmx for protocol
2004-08-05 15:24:23,572 INFO [org.apache.jk.common.ChannelSocket] JK2: ajp13 listening on /0.0.0.0:19210
2004-08-05 15:24:23,578 INFO [org.apache.jk.server.JkMain] Jk running ID=0 time=1/26 config=null
2004-08-05 15:24:23,579 INFO [org.jboss.web.tomcat.tc4.EmbeddedTomcatService] OK
2004-08-05 15:24:23,579 INFO [org.jboss.deployment.MainDeployer] Adding deployer: org.jboss.web.tomcat.tc4.EmbeddedTomcatService@bf1f20
2004-08-05 15:24:23,579 INFO [org.jboss.deployment.MainDeployer] Starting deployment of package: file:/home/brianw/views/wallis_flatcat/vobs/JavaCommon_src/jboss/configs/
default/server/default/deploy/jms/jbossmq-httpil.sar/jbossmq-httpil.war/
2004-08-05 15:24:23,720 INFO [org.jboss.web.tomcat.tc4.EmbeddedTomcatService] deploy, ctxPath=/jbossmq-httpil, warUrl=file:/home/brianw/views/wallis_flatcat/vobs/JavaComm
on_src/jboss/configs/default/server/default/deploy/jms/jbossmq-httpil.sar/jbossmq-httpil.war/
2004-08-05 15:24:24,063 ERROR [org.apache.commons.digester.Digester] Parse Fatal Error at line -1 column -1: Premature end of file.
org.xml.sax.SAXParseException: Premature end of file.

[starksm64]

And when you remove the write mode from the file there is not an exception indicating what is overwriting this file?

[bwallis42]

And when you remove the write mode from the file there is not an exception indicating what is overwriting this file?

No, not a wimper. I also started it up with full tracing on and could find nothing much relevant (see below). I tried using strace but also could not find the culprit, probably because strace tends to miss the early part of a thread's execution before the parent gets a chance to attach to the new thread (according to the strace man page).

The only jboss TRACE entry mentioning web.xml before it is found to be truncated is:

2004-08-06 16:51:32,652 TRACE [org.jboss.mx.loading.UnifiedClassLoader] getResourceLocally(org.jboss.mx.loading.UnifiedClassLoader3@e4776b{ url=file:/home/brianw/views/wallis_flatcat/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=10}), name=web.xml, resURL:file:/home/brianw/views/wallis_flatcat/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/jboss/conf/web.xml

[bwallis42]

OK, found what it is in our configuration that causes web.xml to be overwritten.

For a reason that I cannot quite remember we have always had the server conf directory on our classpath when jboss starts up, something to do with using ClassLoader.getResource() for properties I think, anyway we don't use that anymore. Also when we changed from 3.2.1 to 3.2.3 we also changed from jetty to tomcat.

If I take the conf directory off the classpath then the web.xml file is not truncated, although it's last modified time is still updated.

On a Solaris system I launched the JVM with truss and then matched up the tracing in the JBoss log with the truss output and found the following. (the first log shown at the end is the jboss log followed with the truss log)

The first JBoss timestamp at 2004-08-10 14:37:35,460 corresponds to a time of 123.4634 in the truss log and the last JBoss timestamp is a time of 123.5674 in the truss log so the jboss tracing overlaps the two truss entries shown.

Notice that the second open call in the truss log has flags O_CREATE|O_TRUNC which is going to do exactly that, truncate the web.xml file. This second open call fits into the time between the last two jboss log entries shown which seem to be in the UnifiedClassLoader3.

That's about as far as I can go as I don't know this area of the JBoss code at all.

Is this a bug I should report? The work around is simple, don't put the conf dir on your classpath :-)


jboss log:
======
2004-08-10 14:37:35,460 TRACE [org.jboss.mx.loading.UnifiedClassLoader] getResourceLocally(org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/NotificationSer
vice_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}), name=web.xml, resURL:file:/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/jboss/co
nf/web.xml
2004-08-10 14:37:35,464 TRACE [org.jboss.mx.loading.UnifiedClassLoader3] attempt(1) was: true for :org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/Notific
ationService_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}
2004-08-10 14:37:35,465 TRACE [org.jboss.mx.loading.LoadMgr3] registerLoaderThread, ucl=org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/NotificationServic
e_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}, t=Thread[main,5,jboss], prevT=null
2004-08-10 14:37:35,467 TRACE [org.jboss.mx.loading.LoadMgr3] Begin beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@2c06b2{classname: java.io.FileOutputStream, r
equestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/NotificationService_build/JAVA_dbg/run/NS_EF
D/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}, loadedClass: null, loadOrder: 2147483647, loadException: null, threadTaskCount: 0, state: 0}
2004-08-10 14:37:35,468 TRACE [org.jboss.mx.loading.UnifiedClassLoader] loadClassLocally, name=java.io.FileOutputStream
2004-08-10 14:37:35,469 TRACE [org.jboss.mx.loading.UnifiedLoaderRepository3] cacheLoadedClass, classname: java.io.FileOutputStream, class: class java.io.FileOutputStream,
ucl: org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}
2004-08-10 14:37:35,470 TRACE [org.jboss.mx.loading.LoadMgr3] End beginLoadTask, loadClassFromClassLoader
2004-08-10 14:37:35,472 TRACE [org.jboss.mx.loading.LoadMgr3] Begin endLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@2c06b2{classname: java.io.FileOutputStream, req
uestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/
jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}, loadedClass: class java.io.FileOutputStream@7a78d3<CodeSource: null>, loadOrder: 2147483647, loadException: null, thre
adTaskCount: 0, state: 4}
2004-08-10 14:37:35,473 TRACE [org.jboss.mx.loading.UnifiedClassLoader3] release(1) for :org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/NotificationServi
ce_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}
2004-08-10 14:37:35,474 TRACE [org.jboss.mx.loading.UnifiedClassLoader3] released, holds: 0
2004-08-10 14:37:35,522 TRACE [org.jboss.mx.loading.UnifiedClassLoader3] attempt(1) was: true for :org.jboss.mx.loading.UnifiedClassLoader3@198ee2f{ url=file:/vobs/Notific
ationService_build/JAVA_dbg/run/NS_EFD/jboss/deploy/jbossweb-tomcat41.sar/ ,addedOrder=11}


truss log:
=======

19438: 123.5093 open("/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/jboss/conf/web.xml", O_RDONLY|O_LARGEFILE) = 15
19438: 123.5644 open("/vobs/NotificationService_build/JAVA_dbg/run/NS_EFD/jboss/conf/web.xml", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = 17

[bwallis42]

Forgot to mention, I did try putting the conf directory onto the classpath in an "out of the box" jboss 3.2.3 system and it then also truncates the web.xml file so the problem is nicely reproducable now.

[starksm64]

Yes, create a bug report to track it. I don't see how putting the directory on the classpath can cause this behavior though.