Possible memory leak in eXist

[Leonard Petrica]

Hello,

We have discovered a problem with eXist: after running several
operations the occupied memory increases. I attached two screenshots
from a profiler application used to identify the problem. The
screenshots are from two consecutive runs of our process.
As we compared the results from the two runs we observed an increase of
the memory occupied by an instance of org.exits.storage.BrokerPool (this
is a member of org.exist.xmlrpc.RpcConnection). After the first run the
object occupied about 79MBytes and after the second run 104MBytes.
One important difference we noticed was made by an instance of
org.exist.storage.NotificationService (notificationService from
org.exist.storage.BrokerPool) and an underlying java.lang.Object[].
We performed a manual GC after every run in order to be certain that the
values are correct.

After we run our process, notificationService contains the documents we
are using in the XQuery procedures. Running the process again and
looking in the log files we see that there are duplicate listeners for
the same document. Following you can see a segment of the log file:
---------------
DEBUG: NotificationService: Registered UpdateListeners:
DEBUG: ExtDocument$1: UpdateListener: Line: 1:
document(dynamic-cardinality-check("one or more",
"/db/collection/SomeDocument.xml"))
DEBUG: ExtDocument$1: UpdateListener: Line: 1:
document(dynamic-cardinality-check("one or more",
"/db/collection/SomeDocument.xml"))
---------------

Are these listeners released or is a cleanup made? Is there a caching
method we should be aware?

Best regards,



--
Marian Teodorescu
Core, Modules and Bridges Department
MuseGlobal, S.A.
Craiova, Romania

Tel:   + 40 251 413496
Fax:   + 40 251 418935
Email: marian.teodorescu@...
Url:   http://www.museglobal.ro






-------------------------------------------------------------------------
This SF.net email is sponsored by the 2008 JavaOne(SM) Conference
Don't miss this year's exciting event. There's still time to save $100.
Use priority code J8TL2D2.
http://ad.doubleclick.net/clk;198757673;13503038;p?http://java.sun.com/javaone
_______________________________________________
Exist-open mailing list
Exist-open@...
https://lists.sourceforge.net/lists/listinfo/exist-open

[Wolfgang Meier-2]

Hi,

> One important difference we noticed was made by an instance of
> org.exist.storage.NotificationService (notificationService from
> org.exist.storage.BrokerPool) and an underlying java.lang.Object[].

The listener should be cleared immediately after query execution (via a
call to XQueryContext.reset -> clearUpdateListener).

I had a look at this and found one situation in which the XQueryContext
wasn't cleared properly: if an exception occurred during a call to
util:eval(). Are you using util:eval in your application?

If yes, my bug fix is in trunk:

http://exist.svn.sourceforge.net/exist/?rev=7693&view=rev

If not, we have to check for other possibilities. For debugging, I just
put a breakpoint into NotificationListener.unsubscribe. Since my test
case was single-threaded, size() should have been 0 after unsubscribing
the only listener.

Wolfgang

-------------------------------------------------------------------------
This SF.net email is sponsored by the 2008 JavaOne(SM) Conference
Don't miss this year's exciting event. There's still time to save $100.
Use priority code J8TL2D2.
http://ad.doubleclick.net/clk;198757673;13503038;p?http://java.sun.com/javaone
_______________________________________________
Exist-open mailing list
Exist-open@...
https://lists.sourceforge.net/lists/listinfo/exist-open

[Marian Teodorescu]

>If yes, my bug fix is in trunk:
>http://exist.svn.sourceforge.net/exist/?rev=7693&view=rev

Our application cannot use the trunk version. The eXist API from trunk is different from the one from version 1.2 and changing to the trunk version would require system wide changes in our application. However I inserted the changes from http://exist.svn.sourceforge.net/viewvc/exist?view=rev&revision=7693 in the source of 1.2:
 - cleared the listeners List in XQueryContext.ContextUpdateListener.unsubscribe().
 - in util.Eval moved the following code fragment
              "if (innerContext != this.context)
              innerContext.reset();"     in the finally block.
Running our application with the modified eXist the same listeners were still registered in NotificationService. Maybe the modifications I made in the 1.2 code were not enough or the fix doesn't solve the problem we encountered.
Can you tell me if the changes I made should have solved the problem or can you make a patch for 1.2 version?

Some more information that might help identify the problem:
I observed that for the listeners that remained registered in NotificationService the method XQueryContext.clearUpdateListeners() was called, but the updateListener was null. However the listener was still registered in NotificationService. For one of the listeners XQueryContext.clearUpdateListeners() was not called.
Further investigation led me to the conclusion that the listeners that remain in NotificationService are registered on an XQueryContext and the clearUpdateListeners() method is called for a different XQueryContext. I don't know why for one of the listeners the clearUpdateListeners method was not called.

Stack trace for updateListener stuck in NotificationService:
  at org.exist.storage.NotificationService.subscribe(NotificationService.java:35)
  at org.exist.xquery.XQueryContext.registerUpdateListener(XQueryContext.java:2447)
  at org.exist.xquery.functions.ExtDocument.registerUpdateListener(ExtDocument.java:240)
  at org.exist.xquery.functions.ExtDocument.eval(ExtDocument.java:180)
  at org.exist.xquery.InternalFunctionCall.eval(InternalFunctionCall.java:50)
  at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:59)
  at org.exist.xquery.PathExpr.eval(PathExpr.java:242)
  at org.exist.xupdate.XUpdateProcessor.processQuery(XUpdateProcessor.java:763)
  at org.exist.xupdate.XUpdateProcessor.createVariable(XUpdateProcessor.java:725)
  at org.exist.xupdate.XUpdateProcessor.startVariableDecl(XUpdateProcessor.java:549)
  at org.exist.xupdate.XUpdateProcessor.startElement(XUpdateProcessor.java:333)
  at org.apache.xerces.parsers.AbstractSAXParser.startElement(Unknown Source)
  at org.apache.xerces.parsers.AbstractXMLDocumentParser.emptyElement(Unknown Source)
  at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
  at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
  at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
  at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
  at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
  at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
  at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
  at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)
  at org.exist.xupdate.XUpdateProcessor.parse(XUpdateProcessor.java:254)
  at org.exist.xmldb.LocalXUpdateQueryService.updateResource(LocalXUpdateQueryService.java:86)
  at org.exist.xmldb.LocalXUpdateQueryService.update(LocalXUpdateQueryService.java:141)

The stack trace for a subscription where the updateListener was cleared properly:
  at org.exist.storage.NotificationService.subscribe(NotificationService.java:35)
  at org.exist.xquery.XQueryContext.registerUpdateListener(XQueryContext.java:2447)
  at org.exist.xquery.LocationStep.registerUpdateListener(LocationStep.java:1060)
  at org.exist.xquery.LocationStep.getChildren(LocationStep.java:572)
  at org.exist.xquery.LocationStep.eval(LocationStep.java:293)
  at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:59)
  at org.exist.xquery.PathExpr.eval(PathExpr.java:242)
  at org.exist.xquery.AbstractExpression.eval(AbstractExpression.java:59)
  at org.exist.xquery.XQuery.execute(XQuery.java:219)
  at org.exist.xquery.XQuery.execute(XQuery.java:186)
  at org.exist.xupdate.Modification.select(Modification.java:178)
  at org.exist.xupdate.Modification.selectAndLock(Modification.java:232)
  at org.exist.xupdate.Remove.process(Remove.java:68)
  at org.exist.xmldb.LocalXUpdateQueryService.updateResource(LocalXUpdateQueryService.java:90)
  at org.exist.xmldb.LocalXUpdateQueryService.update(LocalXUpdateQueryService.java:141)

Stack trace for the call to clearUpdateListener when the updateListener was null:
  at org.exist.xquery.XQueryContext.clearUpdateListeners(XQueryContext.java:2454)
  at org.exist.xquery.XQueryContext.reset(XQueryContext.java:1103)
  at org.exist.xquery.XQueryContext.reset(XQueryContext.java:1066)
  at org.exist.xquery.XQuery.execute(XQuery.java:229)
  at org.exist.xquery.XQuery.execute(XQuery.java:186)
  at org.exist.xupdate.Modification.select(Modification.java:178)
  at org.exist.xupdate.Modification.selectAndLock(Modification.java:232)
  at org.exist.xupdate.Append.process(Append.java:76)
  at org.exist.xmldb.LocalXUpdateQueryService.updateResource(LocalXUpdateQueryService.java:90)
  at org.exist.xmldb.LocalXUpdateQueryService.update(LocalXUpdateQueryService.java:141)

Stack trace for cleared update listener:
  at java.lang.Thread.dumpStack(Thread.java:1158)
  at org.exist.xquery.XQueryContext.clearUpdateListeners(XQueryContext.java:2454)
  at org.exist.xquery.XQueryContext.reset(XQueryContext.java:1103)
  at org.exist.xquery.XQueryContext.reset(XQueryContext.java:1066)
  at org.exist.xquery.XQuery.execute(XQuery.java:229)
  at org.exist.xquery.XQuery.execute(XQuery.java:186)
  at org.exist.xupdate.Modification.select(Modification.java:178)
  at org.exist.xupdate.Modification.selectAndLock(Modification.java:232)
  at org.exist.xupdate.Remove.process(Remove.java:68)
  at org.exist.xmldb.LocalXUpdateQueryService.updateResource(LocalXUpdateQueryService.java:90)
  at org.exist.xmldb.LocalXUpdateQueryService.update(LocalXUpdateQueryService.java:141)

[Marian Teodorescu]

Hello,

We used the 1.2.1 release of eXist and the problem with the registered update listeners persists. However we have isolated the source of the unsubscribed update listeners. By running the following xquery you can see that there is still a registered update listener after the xquery completion. Each run of the xquery adds an new update listener in the log file. The problem seems to be caused by this line: "<xu:variable name="record" select="document (concat('/db/tmp/' , '{$ID}' ,'.xml'))/TEST"/>". The registered update listeners can be observed on the eXist log on debug.
Will you please fix this as soon as possible?

let $ID := 'test'
let $xupdate := <xu:modifications version="1.0" xmlns:xu="http://www.xmldb.org/xupdate">
             <xu:variable name="record" select="document (concat('/db/tmp/' , '{$ID}' ,'.xml'))/TEST"/>
             <xu:append select="$record">
                <NAME>recordName</NAME>
             </xu:append>
            </xu:modifications>

let $collectionPath := "/db/tmp"
let $rez := xmldb:update($collectionPath, $xupdate)
return $rez

Marian

[Wolfgang Meier-2]

> Will you please fix this as soon as possible?

If the error is reproducible, I will try to fix it within the next days.
It would be good to have this solved.

Wolfgang

-------------------------------------------------------------------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
Exist-open mailing list
Exist-open@...
https://lists.sourceforge.net/lists/listinfo/exist-open

[Wolfgang Meier-2]

Hi Marian,

> We used the 1.2.1 release of eXist and the problem with the registered
> update listeners persists. However we have isolated the source of the
> unsubscribed update listeners.

With the help of your test, the problem was rather easy to fix:

http://exist.svn.sourceforge.net/exist/?rev=7791&view=rev

Thanks for debugging this issue.

Wolfgang

-------------------------------------------------------------------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
Exist-open mailing list
Exist-open@...
https://lists.sourceforge.net/lists/listinfo/exist-open