Java memory usage:

Novell Identity Manager is an application that runs within the eDirectory application space. What that means is that wherever eDirectory can run, Identity Manager can run, but also that the memory used comes from the pool allocated to eDirectory.

eDirectory in the latest release (8.8.2 for eDirectory and 3.5.1 for Identity Manager, at the time of this writing) are still 32 bit applications, and as such are limited to 2 Giga bytes of RAM for a single process. The memory allocated to eDirectory for caching (iMonitor, Agent Configuration, Database Cache, see:

http://www.novell.com/communities/node/4401/monitoring-edirectory-performance
http://www.novell.com/communities/node/2803/managing-edirectory-database-cache) comes out of that 2 Giga byte memory space, and the Identity Manager application comes out of that 2 Giga byte memory space as well.

Supposedly coming in one of the next few releases of eDirectory (8.8.3 or maybe in 8.8.4) will be a 64 bit version of eDirectory without that kind of memory limit. One of the next releases of Identity Manager (3.6 or maybe later) will support running as a 64 bit version in conjunction with eDirectory 8.8.4 so that we should not have to worry too much in the future. At Brainshare they seemed to be hinting at a summer to fall release time frame. Time will tell what gets released when. Regardless, the 2 Giga byte limit is usually quite workable even with large implementations.

As an update, later in the fall, it turns out that eDirectory 8.8.3 only included 64 bit support for SLES servers, and IDM 3.6 shipped, but 32 bit only. Alas, patience is a virtue, and as I understand it, we will eventually see 64 bit IDM on 64 bit eDir on 64 bit platforms.

The Identity Manager application mostly runs inside a JVM so the usual way to increase the space allocated to IDM is to set the Java variable DHOST_JVM_MAX_HEAP to a new value. The default is shockingly low at 64 Mega bytes. I was actually shocked the other day to learn that the lab environment I was working in, was using the default of 64 Mega bytes, running with 28 drivers, that I was doing some fairly dumb queries in development (testing, I promise, I make sure the dumb idea works first, then optimize for performance). I finally ran out of Java heap when I generated a nodeset with an entry for all sixteen thousand User objects in the tree.

Here is what that kind of error message might look like:

DirXML Log Event -------------------
     Driver:   \ACME-LAB\LAB\SERVICES\IDVAULT\AppX
     Channel:  Subscriber
     Status:   Error
     Message:  Code(-9010) An exception occurred: java.lang.OutOfMemoryError: Java heap space
        at java.lang.AbstractStringBuilder.expandCapacity(Unknown Source)
        at java.lang.AbstractStringBuilder.append(Unknown Source)
        at java.lang.StringBuffer.append(Unknown Source)
        at java.io.StringWriter.write(Unknown Source)
        at com.novell.xml.dom.DOMWriter.writeTree(DOMWriter.java:458)
        at com.novell.nds.dirxml.engine.Trace_DOMWriter.writeTree(Trace_DOMWriter.java:89)
        at com.novell.xml.dom.DOMWriter.writeTree(DOMWriter.java:473)
        at com.novell.nds.dirxml.engine.Trace_DOMWriter.writeTree(Trace_DOMWriter.java:89)
        at com.novell.xml.dom.DOMWriter.writeTree(DOMWriter.java:473)
        at com.novell.nds.dirxml.engine.Trace_DOMWriter.writeTree(Trace_DOMWriter.java:89)
        at com.novell.xml.dom.DOMWriter.writeTree(DOMWriter.java:434)
        at com.novell.nds.dirxml.engine.Trace_DOMWriter.writeTree(Trace_DOMWriter.java:89)
        at com.novell.xml.dom.DOMWriter.write(DOMWriter.java:84)
        at com.novell.nds.dirxml.engine.EngineTrace.traceAlways(EngineTrace.java:930)
        at com.novell.nds.dirxml.engine.EngineTrace.trace(EngineTrace.java:547)
        at com.novell.nds.dirxml.engine.TraceImpl.trace(TraceImpl.java:68)
        at com.novell.nds.dirxml.driver.Trace.trace(Trace.java:375)
        at com.novell.nds.dirxml.driver.XdsQueryProcessor.query(XdsQueryProcessor.java:75)
        at com.novell.nds.dirxml.engine.rules.TokenQuery.expand(TokenQuery.java:274)
        at com.novell.nds.dirxml.engine.rules.Arg.evaluate(Arg.java:378)
        at com.novell.nds.dirxml.engine.rules.DoSetLocalVariable.apply(DoSetLocalVariable.java:100)
        at com.novell.nds.dirxml.engine.rules.ActionSet.apply(ActionSet.java:175)
        at com.novell.nds.dirxml.engine.rules.DirXMLScriptProcessor.applyRules(DirXMLScriptProcessor.java:296)
        at com.novell.nds.dirxml.engine.rules.DirXMLScriptProcessor.applyRules(DirXMLScriptProcessor.java:403)
        at com.novell.nds.dirxml.engine.Subscriber.processEvents(Subscriber.java:924)
        at com.novell.nds.dirxml.engine.Driver.submitTransaction(Driver.java:618)
        at com.novell.nds.dirxml.engine.DriverEntry.submitTransaction(DriverEntry.java:1034)
        at com.novell.nds.dirxml.engine.DriverEntry.processCachedTransaction(DriverEntry.java:918)
        at com.novell.nds.dirxml.engine.DriverEntry.eventLoop(DriverEntry.java:742)
        at com.novell.nds.dirxml.engine.DriverEntry.run(DriverEntry.java:547)
        at java.lang.Thread.run(Unknown Source)

		

It depends on the platform, on Netware you edit the sys:\etc\java.cfg, on Windows you right click on My Computer, Properties, and get to the Environment Variables tab and add one. On Linux you edit the /etc/init.d/ndsd (or more correctly /etc/init.d/pre_ndsd_start but for some reason that does not always work for me, something to do with versions and how the script is called from /etc/init.d) and set the values somewhere near the top like:

DHOST_JVM_MAX_HEAP=256000000
export DHOST_JVM_MAX_HEAP

For more information see:
https://secure-support.novell.com/KanisaPlatform/Publishing/419/3732231_f.SAL_Public.html
http://www.novell.com/communities/node/3018/controlling-memory-allocation-multiple-
edirectory-instances-0

What I recently learned in TID 7000224, is that there is a built in Java class you can call to report the current memory configuration. Awesome! I was very happy to find these. Now I am contemplating how to add trigger a call to these functions via a Libray so that I can use it in every implementation I deal with.

The TID suggests the following code:

<do-trace-message level="0">
<arg-string>
<token-text>Current heap size: </token-text>
<token-xpath expression="java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime())"/>
</arg-string>
</do-trace-message>
<do-trace-message level="0">
<arg-string>
<token-text>Current heap free: </token-text>
<token-xpath expression="java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime())"/>
</arg-string>
</do-trace-message> <do-trace-message level="0">
<arg-string>
<token-text>Maximum heap size: </token-text>
<token-xpath expression="java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime())"/>
</arg-string>
</do-trace-message>

If you try it copied from the TID and pasted in, you will get the following error when you try and restart the driver:

DirXML Log Event -------------------
     Driver:   \ACME-LAB\LAB\SERVICES\IDVAULT\AppX
     Channel:  Subscriber
     Status:   Error
     Message:  Code(-9130) Error in vnd.nds.stream://ACME-LAB/LAB/SERVICES/IDVAULT/AppX/Subscriber/[ACME] Triggered Actions#XmlData:133 : An invalid XPATH expression java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime())' is specified: java.lang.IllegalArgumentException: DOMEvaluator parser error: ')' was expected.
[06/17/08 14:50:51.451]:AppX ST:Driver terminated.

This is because there is a missing close round bracket on each Java function call. So the following would actually work:

<do-trace-message level="0">
	<arg-string>
		<token-text>Current heap size: </token-text>
		<token-xpath expression="java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))"/>
	</arg-string>
</do-trace-message>
<do-trace-message level="0">
	<arg-string>
		<token-text>Current heap free: </token-text>
		<token-xpath expression="java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))"/>
	</arg-string>
</do-trace-message> 
<do-trace-message level="0">
	<arg-string>
		<token-text>Maximum heap size: </token-text>
		<token-xpath expression="java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))"/>
	</arg-string>
</do-trace-message>

You would need to embed these actions in a rule that fires for whatever reason. (I happened to be running some incredibly stupid queries (returning empty nodes for all but 200 of 16,000 users and was looking for ways to do a smarter search, which I did eventually) and so stuck it at the beginning of my Actions in the rule set I was looking at. Here is the trace that the above rules triggered:

[06/17/08 14:57:19.033]:AppX ST:      Action: do-trace-message(level="0","Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 14:57:19.035]:AppX ST:        arg-string("Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 14:57:19.036]:AppX ST:          token-text("Current heap size: ")
[06/17/08 14:57:19.037]:AppX ST:          token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 14:57:19.038]:AppX ST:            Token Value: "66387968".
[06/17/08 14:57:19.038]:AppX ST:          Arg Value: "Current heap size: 66387968".
[06/17/08 14:57:19.039]:AppX ST:Current heap size: 66387968
[06/17/08 14:57:19.040]:AppX ST:      Action: do-trace-message(level="0","Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 14:57:19.042]:AppX ST:        arg-string("Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 14:57:19.042]:AppX ST:          token-text("Current heap free: ")
[06/17/08 14:57:19.044]:AppX ST:          token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 14:57:19.045]:AppX ST:            Token Value: "21380608".
[06/17/08 14:57:19.045]:AppX ST:          Arg Value: "Current heap free: 21380608".
[06/17/08 14:57:19.052]:AppX ST:Current heap free: 21380608
[06/17/08 14:57:19.057]:AppX ST:      Action: do-trace-message(level="0","Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 14:57:19.059]:AppX ST:        arg-string("Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 14:57:19.061]:AppX ST:          token-text("Maximum heap size: ")
[06/17/08 14:57:19.062]:AppX ST:          token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 14:57:19.069]:AppX ST:            Token Value: "66387968".
[06/17/08 14:57:19.070]:AppX ST:          Arg Value: "Maximum heap size: 66387968".
[06/17/08 14:57:19.071]:AppX ST:Maximum heap size: 66387968

You can see in the trace above that the max heap was set to around 64 Mega bytes. (66387968 to be exact). From the line:

[06/17/08 14:57:19.070]:AppX ST:          Arg Value: "Maximum heap size: 66387968".

The current heap after goofing around with some very dumb queries you can see was pretty much 100% at:

[06/17/08 14:57:19.038]:AppX ST:          Arg Value: "Current heap size: 66387968".

To get a feel for what the engine was using on a fresh restart I restarted eDirectory and triggered the event again. (Actually I tried setting the value in the /etc/init.d/pre_ndsd_start file and it did not work, so I grabbed a snippit anyway once I saw it).

[06/17/08 15:11:40.114]:AppX ST:      Action: do-trace-message(level="0","Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 15:11:40.121]:AppX ST:        arg-string("Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 15:11:40.122]:AppX ST:          token-text("Current heap size: ")
[06/17/08 15:11:40.123]:AppX ST:          token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 15:11:40.124]:AppX ST:            Token Value: "50876416".
[06/17/08 15:11:40.125]:AppX ST:          Arg Value: "Current heap size: 50876416".
[06/17/08 15:11:40.126]:AppX ST:Current heap size: 50876416
[06/17/08 15:11:40.126]:AppX ST:      Action: do-trace-message(level="0","Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 15:11:40.129]:AppX ST:        arg-string("Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 15:11:40.130]:AppX ST:          token-text("Current heap free: ")
[06/17/08 15:11:40.131]:AppX ST:          token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 15:11:40.132]:AppX ST:            Token Value: "14211256".
[06/17/08 15:11:40.133]:AppX ST:          Arg Value: "Current heap free: 14211256".
[06/17/08 15:11:40.134]:AppX ST:Current heap free: 14211256
[06/17/08 15:11:40.134]:AppX ST:      Action: do-trace-message(level="0","Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 15:11:40.136]:AppX ST:        arg-string("Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 15:11:40.138]:AppX ST:          token-text("Maximum heap size: ")
[06/17/08 15:11:40.145]:AppX ST:          token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 15:11:40.153]:AppX ST:            Token Value: "66387968".
[06/17/08 15:11:40.154]:AppX ST:          Arg Value: "Maximum heap size: 66387968".
[06/17/08 15:11:40.160]:AppX ST:Maximum heap size: 66387968

So about 50 Mega bytes in use on a fresh engine restart, with all my drivers loaded. This actually has surprised me quite a bit, that I have not run into memory issues to date, considering how many silly things I have done in the development environment.

Then I succeeded in changing the values to 256 Mega bytes as I wanted too, and saw this trace after a fresh restart:

[06/17/08 15:29:11.812]:AppX ST:      Action: do-trace-message(level="0","Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 15:29:11.814]:AppX ST:        arg-string("Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 15:29:11.816]:AppX ST:          token-text("Current heap size: ")
[06/17/08 15:29:11.817]:AppX ST:          token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 15:29:11.819]:AppX ST:            Token Value: "48820224".
[06/17/08 15:29:11.819]:AppX ST:          Arg Value: "Current heap size: 48820224".
[06/17/08 15:29:11.820]:AppX ST:Current heap size: 48820224
[06/17/08 15:29:11.821]:AppX ST:      Action: do-trace-message(level="0","Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 15:29:11.823]:AppX ST:        arg-string("Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 15:29:11.824]:AppX ST:          token-text("Current heap free: ")
[06/17/08 15:29:11.825]:AppX ST:          token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 15:29:11.826]:AppX ST:            Token Value: "15308224".
[06/17/08 15:29:11.827]:AppX ST:          Arg Value: "Current heap free: 15308224".
[06/17/08 15:29:11.827]:AppX ST:Current heap free: 15308224
[06/17/08 15:29:11.828]:AppX ST:      Action: do-trace-message(level="0","Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 15:29:11.830]:AppX ST:        arg-string("Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 15:29:11.832]:AppX ST:          token-text("Maximum heap size: ")
[06/17/08 15:29:11.832]:AppX ST:          token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 15:29:11.834]:AppX ST:            Token Value: "255131648".
[06/17/08 15:29:11.835]:AppX ST:          Arg Value: "Maximum heap size: 255131648".
[06/17/08 15:29:11.836]:AppX ST:Maximum heap size: 255131648

Again, about 48 Mega bytes in use, out of now, closer to 256 Mega bytes maximum.

Then my query that built a nodeset with 16,000 some odd entries in a local variable (have I mentioned before that that is a stupid approach?) and took about 40 minutes to run, finished, and I saw that the heap in use went to the following:

[06/17/08 16:08:15.465]:AppX ST:      Action: do-trace-message(level="0","Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 16:08:15.471]:AppX ST:        arg-string("Current heap size: " token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 16:08:15.477]:AppX ST:          token-text("Current heap size: ")
[06/17/08 16:08:15.478]:AppX ST:          token-xpath("java.lang.Runtime:totalMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 16:08:15.480]:AppX ST:            Token Value: "166805504".
[06/17/08 16:08:15.481]:AppX ST:          Arg Value: "Current heap size: 166805504".
[06/17/08 16:08:15.482]:AppX ST:Current heap size: 166805504
[06/17/08 16:08:15.483]:AppX ST:      Action: do-trace-message(level="0","Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 16:08:15.490]:AppX ST:        arg-string("Current heap free: " token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 16:08:15.496]:AppX ST:          token-text("Current heap free: ")
[06/17/08 16:08:15.497]:AppX ST:          token-xpath("java.lang.Runtime:freeMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 16:08:15.499]:AppX ST:            Token Value: "46170128".
[06/17/08 16:08:15.507]:AppX ST:          Arg Value: "Current heap free: 46170128".
[06/17/08 16:08:15.513]:AppX ST:Current heap free: 46170128
[06/17/08 16:08:15.514]:AppX ST:      Action: do-trace-message(level="0","Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")).
[06/17/08 16:08:15.524]:AppX ST:        arg-string("Maximum heap size: " token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))"))
[06/17/08 16:08:15.526]:AppX ST:          token-text("Maximum heap size: ")
[06/17/08 16:08:15.527]:AppX ST:          token-xpath("java.lang.Runtime:maxMemory((java.lang.Runtime:getRuntime()))")
[06/17/08 16:08:15.529]:AppX ST:            Token Value: "255131648".
[06/17/08 16:08:15.529]:AppX ST:          Arg Value: "Maximum heap size: 255131648".

Interesting to know that a nodeset with 16,000 instance nodes, mostly empty (i.e. Only 270 had actual values, and those were single valued DN's) looks like it took up about 118 Mega bytes of RAM. That comes out to about 7K a node in the nodeset for basically empty nodes. Higher actually than I would have expected. I did not think it would take that much memory. I have never seen anyone show an estimated value for this before, so I thought that was pretty neat. The real number may be lower since I did some operations on the 270 or so nodes that had values and that may have eaten some heap memory, but I cannot imagine it was enough to change the estimate a huge amount.

As a further update, look at the article More thoughts on the size of Node sets where I have found a slightly better value for a node set, closer to 4K a node.

Overall, these function calls are great for trying to see what is going on with RAM, and the TID is great, once you fix the typos in the posted code.