From: Greg B. <bar...@gm...> - 2012-01-20 15:03:20
|
I have noticed that when a query is taking long the following job sometimes starts during it: ID Action Info Running Since DefaultQuartzScheduler_Worker-1 remove collection /db/system/temp 2012-01-20T08:51:35.132-05:00 -- until 2012-01-20T08:59:45-5:00 Notice removing this temp collection is taking over 4 minutes. The long query never finishes. Any relationships? And what is the scheduler doing? Thanks, -- Greg Bardwell bar...@gm... |
From: Dannes W. <da...@ex...> - 2012-01-20 17:30:24
|
Hi, On 20 Jan 2012, at 16:03 , Greg Bardwell wrote: > And what is the scheduler doing? the scheduler schedules..... tasks that must be executed on a regular basis. These can be user tasks, or system tasks (e.g. tasks run automatic backups) cheers Dannes --- eXist-db Native XML Database http://www.exist-db.org |
From: Wolfgang M. <wol...@ex...> - 2012-01-20 17:42:01
|
> Notice removing this temp collection is taking over 4 minutes. > The long query never finishes. The temp collection should not be used anymore! It was causing major problems in older version of eXist. We've been trying to remove all code which generates temporary fragments, but due to the complexity of the code, there might still be situations where the query engine writes into the temp collection. Could you check if your temp collection does actually contain anything? Do you see any messages about "temporary fragments" in your logs? If yes, it could indeed be the cause of your issues and we'll need to find out why it is still used. Wolfgang |
From: Greg B. <bar...@gm...> - 2012-01-20 18:10:27
|
2012-01-20 12:42:13,390 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:13,433 [eXistThread-388] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:13,435 [eXistThread-388] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIFT1/13c52c04-b970-3b74-a1a0-606a22283334 took 557ms. 2012-01-20 12:42:13,623 [eXistThread-368] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:13,624 [eXistThread-368] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:13,624 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:13,625 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:13,625 [eXistThread-368] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:14,539 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:14,539 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@34105c79'. 2012-01-20 12:42:14,543 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:14,543 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@1c59a6cc'. 2012-01-20 12:42:14,548 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:14,548 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@3272e5d6'. 2012-01-20 12:42:14,549 [eXistThread-387] DEBUG (Collection.java [checkPermissions]:1427) - Found old doc 196826 2012-01-20 12:42:14,549 [eXistThread-387] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIMC1/42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 2012-01-20 12:42:14,549 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:14,549 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:14,550 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:14,551 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:14,551 [eXistThread-387] DEBUG (Collection.java [validateXMLResourceInternal]:1288) - removing old document 42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 2012-01-20 12:42:14,551 [eXistThread-387] INFO (NativeBroker.java [removeXMLResource]:2317) - Removing document 42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 (196826) ... 2012-01-20 12:42:15,354 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:15,355 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:15,355 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:15,356 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:15,356 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:15,449 [eXistThread-387] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:15,449 [eXistThread-387] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:15,449 [eXistThread-387] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:15,529 [eXistThread-387] DEBUG (NativeBroker.java [removeXMLResource]:2322) - removeDocument() - removing dom 2012-01-20 12:42:15,531 [eXistThread-387] DEBUG (NativeBroker.java [removeResourceMetadata]:2420) - Removing resource metadata for 196826 2012-01-20 12:42:15,531 [eXistThread-387] DEBUG (Collection.java [validateXMLResourceInternal]:1314) - removed old document 42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 2012-01-20 12:42:15,532 [eXistThread-387] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 196826 ... 2012-01-20 12:42:15,532 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:15,532 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:15,538 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:15,539 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:15,617 [eXistThread-364] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:15,619 [eXistThread-364] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:15,619 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:15,619 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:15,620 [eXistThread-364] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:15,824 [eXistThread-387] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:15,825 [eXistThread-387] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIMC1/42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 took 1277ms. 2012-01-20 12:42:15,834 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:15,835 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@346f4190'. 2012-01-20 12:42:15,839 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:15,839 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@66dd02e8'. 2012-01-20 12:42:15,844 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:15,844 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@643015a3'. 2012-01-20 12:42:15,845 [eXistThread-387] DEBUG (Collection.java [checkPermissions]:1427) - Found old doc 280738 2012-01-20 12:42:15,845 [eXistThread-387] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIFT1/42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 2012-01-20 12:42:15,845 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:15,846 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:15,846 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:15,846 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:15,847 [eXistThread-387] DEBUG (Collection.java [validateXMLResourceInternal]:1288) - removing old document 42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 2012-01-20 12:42:15,847 [eXistThread-387] INFO (NativeBroker.java [removeXMLResource]:2317) - Removing document 42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 (280738) ... 2012-01-20 12:42:15,883 [eXistThread-387] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:15,883 [eXistThread-387] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:15,884 [eXistThread-387] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:16,155 [eXistThread-387] DEBUG (NativeBroker.java [removeXMLResource]:2322) - removeDocument() - removing dom 2012-01-20 12:42:16,156 [eXistThread-387] DEBUG (NativeBroker.java [removeResourceMetadata]:2420) - Removing resource metadata for 280738 2012-01-20 12:42:16,156 [eXistThread-387] DEBUG (Collection.java [validateXMLResourceInternal]:1314) - removed old document 42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 2012-01-20 12:42:16,157 [eXistThread-387] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 280738 ... 2012-01-20 12:42:16,157 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:16,158 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:16,158 [eXistThread-387] DEBUG (DOMFile.java [add]:256) - Creating overflow page 2012-01-20 12:42:16,178 [eXistThread-387] DEBUG (DOMFile.java [<init>]:3370) - Creating overflow page: 1237113 2012-01-20 12:42:16,181 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:16,181 [eXistThread-387] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:16,195 [eXistThread-387] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:16,195 [eXistThread-387] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIFT1/42ddbb08-dc96-3f5e-9e5b-355ffbf1fdf1 took 350ms. 2012-01-20 12:42:16,662 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:16,662 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:16,663 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:16,663 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:16,663 [eXistThread-377] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:18,392 [eXistThread-388] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:18,393 [eXistThread-388] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:18,393 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:18,393 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:18,394 [eXistThread-388] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:19,698 [eXistThread-364] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:19,699 [eXistThread-364] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:19,699 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:19,699 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:19,699 [eXistThread-364] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:20,653 [eXistThread-368] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:20,654 [eXistThread-368] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:20,655 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:20,655 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:20,655 [eXistThread-368] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:21,431 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:21,431 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:21,432 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:21,432 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:21,432 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:21,984 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:21,984 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@417e741f'. 2012-01-20 12:42:21,988 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:21,989 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@58e1c345'. 2012-01-20 12:42:21,994 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:21,995 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@6a2570bd'. 2012-01-20 12:42:21,995 [eXistThread-377] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIMC1/c9668ced-2cb8-3489-8084-f04804e2edc4 2012-01-20 12:42:21,995 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:21,996 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:21,996 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:21,997 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:21,997 [eXistThread-377] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 238024 ... 2012-01-20 12:42:21,997 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:21,997 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:22,445 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:22,445 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:22,734 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:22,735 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:22,736 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:22,736 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:22,736 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:24,469 [eXistThread-387] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:24,470 [eXistThread-387] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:24,470 [eXistThread-387] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:24,471 [eXistThread-387] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:24,471 [eXistThread-387] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:25,653 [eXistThread-377] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:25,655 [eXistThread-377] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIMC1/c9668ced-2cb8-3489-8084-f04804e2edc4 took 3660ms. 2012-01-20 12:42:25,663 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:25,664 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@4bd282fd'. 2012-01-20 12:42:25,668 [eXistThread-364] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:25,669 [eXistThread-364] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@6c51d969'. 2012-01-20 12:42:25,673 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:25,674 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@6054fbbe'. 2012-01-20 12:42:25,674 [eXistThread-368] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIFT1/c9668ced-2cb8-3489-8084-f04804e2edc4 2012-01-20 12:42:25,675 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:25,675 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:25,676 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:25,676 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:25,677 [eXistThread-368] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 196898 ... 2012-01-20 12:42:25,677 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:25,677 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:25,690 [eXistThread-387] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:25,692 [eXistThread-387] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:25,692 [eXistThread-387] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:25,692 [eXistThread-387] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:25,692 [eXistThread-387] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:25,775 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:25,775 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:25,776 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:25,776 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:25,776 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:26,036 [eXistThread-368] DEBUG (DOMFile.java [add]:256) - Creating overflow page 2012-01-20 12:42:26,064 [eXistThread-368] DEBUG (DOMFile.java [<init>]:3370) - Creating overflow page: 1237104 2012-01-20 12:42:26,067 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:26,067 [eXistThread-368] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:26,205 [eXistThread-368] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:26,207 [eXistThread-368] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIFT1/c9668ced-2cb8-3489-8084-f04804e2edc4 took 533ms. 2012-01-20 12:42:27,508 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:27,509 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:27,509 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:27,509 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:27,509 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:28,811 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:28,811 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:28,812 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:28,812 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:28,812 [eXistThread-377] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:29,085 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:29,085 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@37e497b2'. 2012-01-20 12:42:29,090 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:29,090 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@5eb74172'. 2012-01-20 12:42:29,095 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:29,095 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@1119de7f'. 2012-01-20 12:42:29,096 [eXistThread-369] DEBUG (Collection.java [checkPermissions]:1427) - Found old doc 280792 2012-01-20 12:42:29,096 [eXistThread-369] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIMC1/9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 2012-01-20 12:42:29,096 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:29,097 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:29,097 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:29,097 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:29,098 [eXistThread-369] DEBUG (Collection.java [validateXMLResourceInternal]:1288) - removing old document 9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 2012-01-20 12:42:29,098 [eXistThread-369] INFO (NativeBroker.java [removeXMLResource]:2317) - Removing document 9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 (280792) ... 2012-01-20 12:42:30,554 [eXistThread-388] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:30,555 [eXistThread-388] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:30,555 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:30,555 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:30,555 [eXistThread-388] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:30,728 [eXistThread-368] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:30,729 [eXistThread-368] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:30,729 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:30,730 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:30,730 [eXistThread-368] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:31,849 [eXistThread-365] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:31,850 [eXistThread-365] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:31,851 [eXistThread-365] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:31,851 [eXistThread-365] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:31,851 [eXistThread-365] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:33,116 [eXistThread-369] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:33,117 [eXistThread-369] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:33,117 [eXistThread-369] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:33,236 [eXistThread-369] DEBUG (NativeBroker.java [removeXMLResource]:2322) - removeDocument() - removing dom 2012-01-20 12:42:33,554 [eXistThread-369] DEBUG (NativeBroker.java [removeResourceMetadata]:2420) - Removing resource metadata for 280792 2012-01-20 12:42:33,554 [eXistThread-369] DEBUG (Collection.java [validateXMLResourceInternal]:1314) - removed old document 9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 2012-01-20 12:42:33,554 [eXistThread-369] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 280792 ... 2012-01-20 12:42:33,555 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:33,555 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:33,560 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:33,560 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:33,575 [eXistThread-369] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:33,577 [eXistThread-369] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIMC1/9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 took 4481ms. 2012-01-20 12:42:33,584 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:33,585 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@29a8186c'. 2012-01-20 12:42:33,589 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:33,589 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@7c8a30f0'. 2012-01-20 12:42:33,592 [eXistThread-364] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:33,592 [eXistThread-364] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:33,593 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:33,593 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:33,593 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:33,593 [eXistThread-364] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:33,594 [eXistThread-369] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@43af15e3'. 2012-01-20 12:42:33,594 [eXistThread-369] DEBUG (Collection.java [checkPermissions]:1427) - Found old doc 279976 2012-01-20 12:42:33,595 [eXistThread-369] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIFT1/9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 2012-01-20 12:42:33,595 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:33,595 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:33,596 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:33,596 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:33,596 [eXistThread-369] DEBUG (Collection.java [validateXMLResourceInternal]:1288) - removing old document 9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 2012-01-20 12:42:33,596 [eXistThread-369] INFO (NativeBroker.java [removeXMLResource]:2317) - Removing document 9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 (279976) ... 2012-01-20 12:42:33,628 [eXistThread-369] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:33,628 [eXistThread-369] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:33,629 [eXistThread-369] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:33,730 [eXistThread-369] DEBUG (NativeBroker.java [removeXMLResource]:2322) - removeDocument() - removing dom 2012-01-20 12:42:33,756 [eXistThread-369] DEBUG (NativeBroker.java [removeResourceMetadata]:2420) - Removing resource metadata for 279976 2012-01-20 12:42:33,757 [eXistThread-369] DEBUG (Collection.java [validateXMLResourceInternal]:1314) - removed old document 9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 2012-01-20 12:42:33,757 [eXistThread-369] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 279976 ... 2012-01-20 12:42:33,757 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:33,758 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:33,759 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:33,759 [eXistThread-369] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:33,799 [eXistThread-369] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:33,800 [eXistThread-369] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIFT1/9ff4fedd-7ff1-30f8-bd02-b4ff2af5e036 took 206ms. 2012-01-20 12:42:34,890 [eXistThread-365] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:34,890 [eXistThread-365] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:34,890 [eXistThread-365] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:34,891 [eXistThread-365] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:34,891 [eXistThread-365] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:35,793 [eXistThread-364] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:35,795 [eXistThread-364] DEBUG (XQuery.java [execute]:249) - Execution took 2 ms 2012-01-20 12:42:35,795 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:35,795 [eXistThread-364] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:35,796 [eXistThread-364] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:36,415 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:36,415 [eXistThread-368] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@1828b826'. 2012-01-20 12:42:36,420 [eXistThread-364] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:36,420 [eXistThread-364] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@4aff7dfe'. 2012-01-20 12:42:36,425 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:36,426 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@39429d8d'. 2012-01-20 12:42:36,426 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIMC1/34892d16-6f92-398e-8e69-ea61aae6f6b4 2012-01-20 12:42:36,426 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:36,427 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:36,427 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:36,428 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:36,429 [eXistThread-365] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 280810 ... 2012-01-20 12:42:36,429 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:36,429 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:36,630 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:36,632 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:36,632 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:36,633 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:36,633 [eXistThread-377] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:36,747 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:36,747 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:37,926 [eXistThread-368] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:37,927 [eXistThread-368] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:37,928 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:37,928 [eXistThread-368] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:37,928 [eXistThread-368] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:38,163 [eXistThread-365] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:38,164 [eXistThread-365] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIMC1/34892d16-6f92-398e-8e69-ea61aae6f6b4 took 1738ms. 2012-01-20 12:42:38,171 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:38,171 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@35bb43c5'. 2012-01-20 12:42:38,176 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:38,176 [eXistThread-387] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@64c4c1'. 2012-01-20 12:42:38,181 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:38,182 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@3cd434f0'. 2012-01-20 12:42:38,182 [eXistThread-377] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIFT1/34892d16-6f92-398e-8e69-ea61aae6f6b4 2012-01-20 12:42:38,183 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:38,183 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:38,183 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:38,184 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:38,184 [eXistThread-377] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 196901 ... 2012-01-20 12:42:38,185 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:38,185 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:38,291 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:38,292 [eXistThread-377] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:38,552 [eXistThread-377] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:38,553 [eXistThread-377] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIFT1/34892d16-6f92-398e-8e69-ea61aae6f6b4 took 371ms. 2012-01-20 12:42:39,668 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:39,669 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:39,669 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:39,669 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:39,669 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:40,832 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:40,834 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:40,834 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:40,834 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:40,834 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:40,969 [eXistThread-387] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:40,970 [eXistThread-387] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:40,970 [eXistThread-387] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:40,970 [eXistThread-387] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:40,971 [eXistThread-387] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:42,704 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:42,705 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:42,705 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:42,706 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:42,706 [eXistThread-377] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:43,165 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:43,165 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@4a4416ea'. 2012-01-20 12:42:43,170 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:43,170 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@28ab6530'. 2012-01-20 12:42:43,175 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:43,176 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@39c0a01d'. 2012-01-20 12:42:43,176 [eXistThread-365] DEBUG (Collection.java [checkPermissions]:1427) - Found old doc 196835 2012-01-20 12:42:43,176 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIMC1/f16c1bd7-b078-39c4-9d15-895a9d1f2a13 2012-01-20 12:42:43,176 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:43,177 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:43,177 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:43,178 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:43,178 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1288) - removing old document f16c1bd7-b078-39c4-9d15-895a9d1f2a13 2012-01-20 12:42:43,178 [eXistThread-365] INFO (NativeBroker.java [removeXMLResource]:2317) - Removing document f16c1bd7-b078-39c4-9d15-895a9d1f2a13 (196835) ... 2012-01-20 12:42:44,011 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:44,012 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:44,012 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:44,012 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:44,013 [eXistThread-377] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:44,466 [eXistThread-365] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:44,467 [eXistThread-365] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:44,467 [eXistThread-365] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:44,478 [eXistThread-365] DEBUG (NativeBroker.java [removeXMLResource]:2322) - removeDocument() - removing dom 2012-01-20 12:42:44,524 [eXistThread-365] DEBUG (NativeBroker.java [removeResourceMetadata]:2420) - Removing resource metadata for 196835 2012-01-20 12:42:44,524 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1314) - removed old document f16c1bd7-b078-39c4-9d15-895a9d1f2a13 2012-01-20 12:42:44,525 [eXistThread-365] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 196835 ... 2012-01-20 12:42:44,525 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:44,525 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:44,531 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:44,531 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:44,545 [eXistThread-365] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:44,545 [eXistThread-365] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIMC1/f16c1bd7-b078-39c4-9d15-895a9d1f2a13 took 1369ms. 2012-01-20 12:42:44,552 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:44,553 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@5076207a'. 2012-01-20 12:42:44,556 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:44,557 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@5321a574'. 2012-01-20 12:42:44,561 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:44,561 [eXistThread-365] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@7c10616a'. 2012-01-20 12:42:44,561 [eXistThread-365] DEBUG (Collection.java [checkPermissions]:1427) - Found old doc 280747 2012-01-20 12:42:44,562 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIFT1/f16c1bd7-b078-39c4-9d15-895a9d1f2a13 2012-01-20 12:42:44,562 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:44,562 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:44,563 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:44,563 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:44,564 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1288) - removing old document f16c1bd7-b078-39c4-9d15-895a9d1f2a13 2012-01-20 12:42:44,564 [eXistThread-365] INFO (NativeBroker.java [removeXMLResource]:2317) - Removing document f16c1bd7-b078-39c4-9d15-895a9d1f2a13 (280747) ... 2012-01-20 12:42:44,608 [eXistThread-365] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:44,608 [eXistThread-365] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:44,609 [eXistThread-365] DEBUG (NativeTextEngine.java [dropIndex]:1072) - Removing 0 tokens 2012-01-20 12:42:44,630 [eXistThread-365] DEBUG (NativeBroker.java [removeXMLResource]:2322) - removeDocument() - removing dom 2012-01-20 12:42:44,682 [eXistThread-365] DEBUG (NativeBroker.java [removeResourceMetadata]:2420) - Removing resource metadata for 280747 2012-01-20 12:42:44,682 [eXistThread-365] DEBUG (Collection.java [validateXMLResourceInternal]:1314) - removed old document f16c1bd7-b078-39c4-9d15-895a9d1f2a13 2012-01-20 12:42:44,683 [eXistThread-365] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 280747 ... 2012-01-20 12:42:44,684 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:44,684 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:44,685 [eXistThread-365] DEBUG (DOMFile.java [add]:256) - Creating overflow page 2012-01-20 12:42:44,709 [eXistThread-365] DEBUG (DOMFile.java [<init>]:3370) - Creating overflow page: 1237096 2012-01-20 12:42:44,712 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:44,712 [eXistThread-365] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:44,725 [eXistThread-365] DEBUG (Collection.java [storeXMLInternal]:1026) - document stored. 2012-01-20 12:42:44,725 [eXistThread-365] DEBUG (RpcConnection.java [parse]:1996) - parsing /db/IQI1/IQIFT1/f16c1bd7-b078-39c4-9d15-895a9d1f2a13 took 164ms. 2012-01-20 12:42:45,743 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:45,744 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:45,744 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:45,744 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:45,744 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:45,870 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:45,871 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:45,872 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:45,872 [eXistThread-377] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:45,872 [eXistThread-377] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:47,061 [eXistThread-388] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:47,061 [eXistThread-388] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:47,062 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:47,062 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:47,062 [eXistThread-388] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:48,779 [eXistThread-388] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:48,779 [eXistThread-388] DEBUG (XQuery.java [execute]:249) - Execution took 0 ms 2012-01-20 12:42:48,780 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:48,780 [eXistThread-388] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:48,780 [eXistThread-388] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:50,097 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:50,098 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:50,098 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:50,098 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:50,099 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:50,808 [DefaultQuartzScheduler_Worker-3] DEBUG (NGramIndex.java [sync]:91) - SYNC NGRAM 2012-01-20 12:42:50,808 [DefaultQuartzScheduler_Worker-3] INFO (NativeBroker.java [sync]:3268) - Memory: 1,439,744K total; 1,439,744K max; 183,277K free 2012-01-20 12:42:50,809 [DefaultQuartzScheduler_Worker-3] INFO (BTree.java [printStatistics]:2420) - dom.dbx INDEX Buffers occupation : 83% (910 out of 1093) Cache efficiency : 99% 2012-01-20 12:42:50,809 [DefaultQuartzScheduler_Worker-3] INFO (DOMFile.java [printStatistics]:1441) - dom.dbx DATA Buffers occupation : 100% (255 out of 256) Cache efficiency : 100% 2012-01-20 12:42:50,809 [DefaultQuartzScheduler_Worker-3] INFO (BTree.java [printStatistics]:2420) - collections.dbx INDEX Buffers occupation : 100% (144 out of 144) Cache efficiency : 95% 2012-01-20 12:42:50,809 [DefaultQuartzScheduler_Worker-3] INFO (BFile.java [printStatistics]:434) - collections.dbx DATA Buffers occupation : 90% (6194 out of 6851) Cache efficiency : 94% 2012-01-20 12:42:50,810 [DefaultQuartzScheduler_Worker-3] INFO (BTree.java [printStatistics]:2420) - values.dbx INDEX Buffers occupation : 100% (8295 out of 8295) Cache efficiency : 82% 2012-01-20 12:42:50,810 [DefaultQuartzScheduler_Worker-3] INFO (BFile.java [printStatistics]:434) - values.dbx DATA Buffers occupation : 100% (8562 out of 8563) Cache efficiency : 54% 2012-01-20 12:42:50,810 [DefaultQuartzScheduler_Worker-3] DEBUG (BrokerPool.java [sync]:1587) - Major sync 2012-01-20 12:42:50,810 [DefaultQuartzScheduler_Worker-3] DEBUG (Journal.java [checkpoint]:328) - Checkpoint reached 2012-01-20 12:42:50,811 [DefaultQuartzScheduler_Worker-3] DEBUG (NotificationService.java [debug]:94) - Registered UpdateListeners: 2012-01-20 12:42:50,925 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:50,926 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:50,926 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:50,927 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:50,927 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:51,625 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:51,625 [eXistThread-377] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@38dea1'. 2012-01-20 12:42:51,630 [eXistThread-364] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:51,630 [eXistThread-364] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@42978a93'. 2012-01-20 12:42:51,636 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:409) - Authentication try for 'admin'. 2012-01-20 12:42:51,636 [eXistThread-388] DEBUG (SecurityManagerImpl.java [authenticate]:434) - Authenticated by 'exist' as 'org.exist.security.internal.SubjectImpl@15b327bb'. 2012-01-20 12:42:51,637 [eXistThread-388] DEBUG (Collection.java [validateXMLResourceInternal]:1283) - Scanning document /db/IQI1/IQIMC1/e9ae99c3-b4f7-30e0-9ffe-246fab5fa6ed 2012-01-20 12:42:51,637 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:51,637 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:51,639 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:51,639 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:51,640 [eXistThread-388] DEBUG (Collection.java [storeXMLInternal]:1013) - storing document 165481 ... 2012-01-20 12:42:51,640 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:51,640 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:51,815 [eXistThread-369] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:51,816 [eXistThread-369] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:51,816 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: type = xml 2012-01-20 12:42:51,817 [eXistThread-369] DEBUG (XQueryContext.java [checkOptions]:3367) - Setting serialization property from pragma: media-type = text/xml 2012-01-20 12:42:51,817 [eXistThread-369] DEBUG (HTTPUtils.java [addLastModifiedHeader]:61) - mostRecentDocumentTime: 0 2012-01-20 12:42:51,943 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (http://www.w3.org/TR/REC-xml). 2012-01-20 12:42:51,944 [eXistThread-388] DEBUG (GrammarPool.java [retrieveInitialGrammarSet]:85) - Found 0 grammars. 2012-01-20 12:42:53,133 [eXistThread-377] DEBUG (HttpRequestWrapper.java [<init>]:129) - Retrieved 1 parameters. 2012-01-20 12:42:53,134 [eXistThread-377] DEBUG (XQuery.java [execute]:249) - Execution took 1 ms 2012-01-20 12:42:53,1... [truncated message content] |
From: Greg B. <bar...@gm...> - 2012-01-20 17:55:15
|
Unfortunately the 'db/system/temp' collection has been removed -- that was the command. However, I have checked when the remove command was running -- it runs a long time -- and I have seen it. hmmm... but... let me try... When I run some queries that are resource hogs it actually creates a temp collection -- I just tried this. So I do see it now. But the db fails to respond when I tried to look in the temp collection. Everything locks, I can not view status or do login or anything. It is now locked. A clue? On Fri, Jan 20, 2012 at 12:41 PM, Wolfgang Meier <wol...@ex...>wrote: > > Notice removing this temp collection is taking over 4 minutes. > > The long query never finishes. > > The temp collection should not be used anymore! It was causing major > problems in older version of eXist. We've been trying to remove all > code which generates temporary fragments, but due to the complexity of > the code, there might still be situations where the query engine > writes into the temp collection. > > Could you check if your temp collection does actually contain > anything? Do you see any messages about "temporary fragments" in your > logs? > > If yes, it could indeed be the cause of your issues and we'll need to > find out why it is still used. > > Wolfgang > -- Greg Bardwell 301-910-2199 (C) 301-299-0254 (W) bar...@gm... |
From: Wolfgang M. <wol...@ex...> - 2012-01-20 18:15:17
|
> When I run some queries that are resource hogs it actually creates a temp > collection -- I just tried this. > So I do see it now. Aha! We definitely should try to figure out which code triggers the creation of the temp collection. I'll need your help here. Could you edit src/org/exist/xquery/XQueryContext and change the log statement in line 3169 to LOG.warn( "Stored: " + targetDoc.getDocId() + ": " + targetDoc.getURI(), new Throwable() ); Next, run the queries again one by one and watch the logs for the corresponding warning. You should get a stack trace leading to the expression which causes the problem. Send me the entire trace plus the query please. Wolfgang |
From: Wolfgang M. <wol...@ex...> - 2012-02-02 17:39:55
|
Hi Greg, I finally managed to track the creation of the temp collection to a single statement in your query, which has the form if ($data/x and $data/y and not($z)) then The caused eXist to write a temporary XML fragment into /db/system/temp. We know this can result in major issues and already tried to remove all cases where this happens for 1.4. Obviously we missed this one. It is likely that the creation of temporary XML fragments is introducing some instability, so I would recommend to update to rev 15784. Wolfgang |
From: Greg B. <bar...@gm...> - 2012-02-02 17:44:14
|
Thank you Wolfgang! I know this is all a lot of work! And we all really appreciate it. We will try that build. My Best, Greg On Thu, Feb 2, 2012 at 12:12 PM, Wolfgang Meier <wol...@ex...>wrote: > Hi Greg, > > I finally managed to track the creation of the temp collection to a > single statement in your query, which has the form > > if ($data/x and $data/y and not($z)) then > > The caused eXist to write a temporary XML fragment into > /db/system/temp. We know this can result in major issues and already > tried to remove all cases where this happens for 1.4. Obviously we > missed this one. It is likely that the creation of temporary XML > fragments is introducing some instability, so I would recommend to > update to rev 15784. > > Wolfgang > -- Greg Bardwell 301-910-2199 (C) 301-299-0254 (W) bar...@gm... |