SourceForge.net Logo
Main Overview Wiki Issues Forum Build Fisheye

Welcome, Guest
Guest Settings
Help

Compass Support Forums » Compass » Compass Users

Thread: JdbcDirectory - IndexWriter open/close Performance degrades with every call

This question is answered. Helpful answers available: 2. Correct answers available: 1.


Permlink Replies: 2 - Pages: 1 - Last Post: Apr 19, 2010 3:30 AM Last Post By: tkrah
tkrah

Posts: 3
Registered: 4/14/10
JdbcDirectory - IndexWriter open/close Performance degrades with every call
Posted: Apr 14, 2010 6:35 AM
 
  Click to reply to this thread Reply
I am using the JdbcDirectory in a JTA environment to make my index transactional (like my jdbc resource).
At the moment the application used does use "some" anti pattern and open and closed the indexwriter very often while performing a lot of work (not changeable).

Using FSDirectory there no "real" performance loss but using the JdbcDirectory the open and close times are growing (most of the time - see example output) with every new IndexWriter(...) + commit() / close() call.

2010-04-14 13:32:28,491 [main]           INFO  de.test.index.IndexTester - 20 found.
2010-04-14 13:32:28,508 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.015s
2010-04-14 13:32:28,536 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 1 in 0.028s.
2010-04-14 13:32:28,620 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.084s.
2010-04-14 13:32:28,659 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.039s
2010-04-14 13:32:28,660 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 2 in 0.001s.
2010-04-14 13:32:28,747 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.087s.
2010-04-14 13:32:28,809 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.062s
2010-04-14 13:32:28,810 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 3 in 0.001s.
2010-04-14 13:32:28,962 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.152s.
2010-04-14 13:32:29,063 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.101s
2010-04-14 13:32:29,064 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 4 in 0.001s.
2010-04-14 13:32:29,230 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.166s.
2010-04-14 13:32:29,448 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.218s
2010-04-14 13:32:29,449 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 5 in 0.0s.
2010-04-14 13:32:29,700 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.251s.
2010-04-14 13:32:29,951 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.25s
2010-04-14 13:32:29,952 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 6 in 0.0s.
2010-04-14 13:32:30,310 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.358s.
2010-04-14 13:32:30,670 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.36s
2010-04-14 13:32:30,671 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 7 in 0.0s.
2010-04-14 13:32:31,123 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.452s.
2010-04-14 13:32:31,644 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.521s
2010-04-14 13:32:31,645 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 8 in 0.001s.
2010-04-14 13:32:32,247 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.602s.
2010-04-14 13:32:32,939 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.692s
2010-04-14 13:32:32,940 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 9 in 0.0s.
2010-04-14 13:32:33,734 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.794s.
2010-04-14 13:32:34,642 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.908s
2010-04-14 13:32:34,643 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 10 in 0.0s.
2010-04-14 13:32:36,870 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 2.227s.
2010-04-14 13:32:37,035 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.165s
2010-04-14 13:32:37,035 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 11 in 0.0s.
2010-04-14 13:32:37,380 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.345s.
2010-04-14 13:32:37,674 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.294s
2010-04-14 13:32:37,674 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 12 in 0.0s.
2010-04-14 13:32:38,145 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.47s.
2010-04-14 13:32:38,582 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.437s
2010-04-14 13:32:38,583 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 13 in 0.001s.
2010-04-14 13:32:39,191 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.608s.
2010-04-14 13:32:39,788 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.596s
2010-04-14 13:32:39,789 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 14 in 0.001s.
2010-04-14 13:32:40,566 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.777s.
2010-04-14 13:32:41,356 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.789s
2010-04-14 13:32:41,356 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 15 in 0.0s.
2010-04-14 13:32:42,320 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.963s.
2010-04-14 13:32:43,326 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 1.005s
2010-04-14 13:32:43,327 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 16 in 0.001s.
2010-04-14 13:32:44,501 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 1.174s.
2010-04-14 13:32:45,756 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 1.255s
2010-04-14 13:32:45,757 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 17 in 0.0s.
2010-04-14 13:32:47,185 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 1.428s.
2010-04-14 13:32:48,731 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 1.546s
2010-04-14 13:32:48,732 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 18 in 0.001s.
2010-04-14 13:32:50,435 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 1.703s.
2010-04-14 13:32:52,313 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 1.877s
2010-04-14 13:32:52,313 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 19 in 0.0s.
2010-04-14 13:32:56,541 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 4.228s.
2010-04-14 13:32:56,848 [main]           INFO  de.test.index.IndexServiceImpl - Index opened in: 0.307s
2010-04-14 13:32:56,849 [main]           INFO  de.test.index.IndexServiceImpl - Indexing done of 20 in 0.001s.
2010-04-14 13:32:57,493 [main]           INFO  de.test.index.IndexServiceImpl - Index commit + close done in 0.644s.


Anyone an idea why this is happening (to understand the problem) and maybe what i can do against those performance loss? thx.

Edited by: tkrah on Apr 14, 2010 6:43 AM
pangea

Posts: 368
Registered: 9/25/07
Re: JdbcDirectory - IndexWriter open/close Performance degrades with every call
Posted: Apr 14, 2010 8:13 PM   in response to: tkrah in response to: tkrah
 
  Click to reply to this thread Reply
for each commit, a new segment is created and merging might happen (based on the max segments cfg).

1) i think u can disable merging be disabling the optimizer and running the optimizer only in batch mode..

2) u can also do the WRITE operation async

those are my general suggestions...
tkrah

Posts: 3
Registered: 4/14/10
Re: JdbcDirectory - IndexWriter open/close Performance degrades with every call
Posted: Apr 19, 2010 3:30 AM   in response to: tkrah in response to: tkrah
 
  Click to reply to this thread Reply
I've got the cause - which is not obvious to find without digging into the code.
I am using CMT. All is done via Spring transaction management. However - the jdbcTemplate used by the jdbcDirectory does call DataSourceUtils.close after its work is done and it is doing the close call on the connection (the check for proxy stuff fails) - although the transaction is not done.
I must use Springs TransactionDatasourceAwareProxy to get things working. The con is not closed anymore after this if a transaction is already running and things are "fast" again.
Legend
Guru: 2001 + pts
Expert: 501 - 2000 pts
Super-star: 101 - 500 pts
Assistant: 51 - 100 pts
Participant: 0 - 50 pts
Helpful Answer (5 pts)
Correct Answer (10 pts)

Point your RSS reader here for a feed of the latest messages in all forums