List.ds.xml

[acarur01]

We are currently testing performance and have noticed quite a few requests for List.ds.xml - could you identify which control(s) uses this file and is there any reason why it is not cached? Or if it is up to us to make sure it is cached?

[Isomorphic]

Presumably you mean server-side file access, since there is never a network request for this file. There is already caching, but we will check for staleness (just looking at last modified time) periodically.

[acarur01]

Ok. So what is using this file exactly or how is this file being used if you don't mind me asking?

[Isomorphic]

It's an internal file that defines how arrays of values defined in XML files a processed.

[acarur01]

Relaying some questions:

Which part of smartclient code uses it?

Client-side (requested from browser) or server side (servlets)?

And how do they access it (new File(...), new FileInputStream(...), Class.getResourceAsStream(...), etc..

[Isomorphic]

Server-side, and a variety of methods.

Please let us know if you have some kind of definitive diagnostics indicating that access to this file has a non-negligible impact on performance. Until you have this (which is extremely improbable), there's no point discussing how this file functions, as it is entirely internal.

[acarur01]

On a linux system, we are load testing our application under weblogic and jboss.

Under jboss, all is fine.

Under weblogic, we run out of file descriptors (we have 65536 available), and 99.9% of open files are List.ds.xml (according to `lsof` command)

That's why it is important to know which java API you use to access this file, because there is apparent difference in behaviour between weblogic and jboss in this case.

[Isomorphic]

OK, start with that information next time :) If we don't know why you're asking, we have no idea what aspect of the behavior List.ds.xml might need to be discussed.

Our best guess is that WebLogic has a bug where calling java.io.File.lastModified() leaks a file descriptor.

To confirm this, try setting the log category com.isomorphic.xml.XML to DEBUG. You should one log of parsing List.ds.xml ever per WebLogic startup. If you see more than one, please show us the complete server logs for a startup and whatever minimal series of server requests can produce a second log.

If there's only one parse Log ever, please see if you can confirm this as a WebLogic bug with your WebLogic support.

[Isomorphic]

Note: this could also be a JDK-level bug. WebLogic typically uses it's own JRockit JVM which may differ from whatever JBoss is using. You may be able to test whether this is the problem by reconfiguring WebLogic to use the same JVM that JBoss is running with.

[acarur01]

Ok, more information:

weblogic runs on a regular 1.6 sun jdk (same version as jboss) so it's not a JDK problem

I tried enabling "com.isomorphic.xml.XML" category in log4j configuration, still didn't see a single event logged. Any specific instruction on how to set this?

And here is the question: how often do you call java.io.File.lastModified() on this file? Once per request? Because the number of file descriptors used by this file grows very fast, hundreds per second

[Isomorphic]

If you are working with the standard SDK then you just add this to log4j.isc.config.xml:

	<category name="com.isomorphic.xml.XML">
	  <priority value="DEBUG" />
	</category>

.. and you will now see log messages every time an XML document is parsed, such as:

=== 2011-02-03 11:13:56,817 [main] DEBUG XML - Parsed XML from /Users/charles/dev/cvs/main/isomorphic/smartclient/client/schema/FormItem.ds.xml: 4ms

If the lastModified() call was triggering the leak, we'd expect at most one new file descriptor per 500ms.

[jimmi1977]

Ok, the logging actually works, we get a lot of the following entries (seemingly for every request):

15:11:24.508 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'-upadmin] DEBUG com.isomorphic.xml.XML - Parsed XML from (in memory stream): 1ms
15:11:24.529 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'-upadmin] DEBUG com.isomorphic.xml.XML - Parsed XML from (in memory stream): 2ms
15:11:24.533 [[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'-upadmin] DEBUG com.isomorphic.xml.XML - Parsed XML from (in memory stream): 2ms
15:11:24.748 [[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'-upadmin] DEBUG com.isomorphic.xml.XML - Parsed XML from (in memory stream): 2ms

[Isomorphic]

That's normal and just indicates parsing of the inbound request, which is XML. Again, you need to see if there is more than one attempt to specifically parse List.ds.xml.

[jimmi1977]

Wow. Very strange indeed. Only 1 entry:

15:49:06.153 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'-upadmin] DEBUG com.isomorphic.xml.XML - Parsed XML from __USE_CONTAINER__/isomorphic/system/schema/List.ds.xml: 2ms

Where can weblogic possibly leak hundreds of file descriptors per second??? With the file List.ds.xml?

[Isomorphic]

OK, then it has to be related to the staleness checks.

I see you've got the system configured for container IO mode, meaning our code obtains files via servletContext.getResource(). The WebLogic file descriptor leak has to be related to this call or the subsequent interactions with the URL object returned. Are you able to provide a real filesystem path for webroot instead (at least to test)?