Hi Damir,
I've managed to reproduce with java version "1.7.0_51" so that can likely be ruled out. Thanks for all your help. We'll keep you posted: https://trac.openmicroscopy.org.uk/ome/ticket/12279
~Josh.
omero@quid:~/OMERO.server/var/log$ more Indexer-0.log
2014-05-28 11:02:32,374 INFO [ ome.services.blitz.Entry] ( main) Waiting 10000 ms on startup
2014-05-28 11:02:42,391 INFO [ ome.services.blitz.Entry] ( main) Creating ome.fulltext. Please wait...
2014-05-28 11:02:43,943 INFO [ ome.services.util.DBUserCheck] ( main) User root.id = 0
2014-05-28 11:02:43,945 INFO [ ome.services.util.DBUserCheck] ( main) User guest.id = 1
2014-05-28 11:02:43,945 INFO [ ome.services.util.DBUserCheck] ( main) Group system.id = 0
2014-05-28 11:02:43,945 INFO [ ome.services.util.DBUserCheck] ( main) Group user.id = 1
2014-05-28 11:02:43,945 INFO [ ome.services.util.DBUserCheck] ( main) Group guest.id = 2
2014-05-28 11:02:43,948 INFO [ ome.services.util.JvmSettingsCheck] ( main) Java version: 1.7.0_11; Linux; amd64; 3.2.0-43-generic
2014-05-28 11:02:43,949 INFO [ ome.services.util.JvmSettingsCheck] ( main) Max Memory (MB): = 910
2014-05-28 11:02:43,950 INFO [ ome.services.util.JvmSettingsCheck] ( main) OS Memory (MB): = 60389
2014-05-28 11:02:43,950 INFO [ ome.services.util.JvmSettingsCheck] ( main) Processors: = 16
2014-05-28 11:02:43,985 INFO [.s.ShutdownSafeEhcacheManagerFactoryBean] ( main) Initializing EHCache CacheManager
2014-05-28 11:02:46,393 INFO [ ome.services.fulltext.FullTextAnalyzer] ( main) Initialized FullTextAnalyzer
2014-05-28 11:02:49,449 INFO [ ome.services.fulltext.FullTextThread] ( main) Initializing Full-Text Indexer
2014-05-28 11:02:49,764 INFO [ ome.services.db.DatabaseIdentity] ( main) Using LSID format: urn:lsid:export.openmicroscopy.org:%s
:27822266-e5fc-4003-8b01-2c3f102c2e79_%s%s
2014-05-28 11:02:49,936 INFO [ ome.tools.hibernate.ExtendedMetadata] ( main) Calculating ExtendedMetadata...
2014-05-28 11:02:50,071 INFO [ o.s.scheduler.SchedulerFactoryBean] ( main) Starting Quartz Scheduler now
2014-05-28 11:02:50,147 INFO [ ome.services.blitz.Entry] ( main) ome.fulltext now accepting connections.
2014-05-28 11:02:50,380 INFO [ ome.security.basic.CurrentDetails] (2-thread-2) Adding log:INSERT,class ome.model.meta.Session,9065
2014-05-28 11:03:41,862 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-2) INDEXED 50 objects in 1 batch(es) [51402 ms.]
2014-05-28 11:03:41,865 ERROR [ ome.services.util.ServiceHandler] (2-thread-2) Method interface ome.services.util.Executor$Work.doWork
invocation took 51433
2014-05-28 11:04:32,672 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-3) INDEXED 50 objects in 1 batch(es) [50782 ms.]
2014-05-28 11:04:32,675 ERROR [ ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork
invocation took 50793
2014-05-28 11:05:23,285 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-4) INDEXED 50 objects in 1 batch(es) [50578 ms.]
2014-05-28 11:05:23,287 ERROR [ ome.services.util.ServiceHandler] (2-thread-4) Method interface ome.services.util.Executor$Work.doWork
invocation took 50592
2014-05-28 11:06:13,813 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-1) INDEXED 50 objects in 1 batch(es) [50498 ms.]
2014-05-28 11:06:13,816 ERROR [ ome.services.util.ServiceHandler] (2-thread-1) Method interface ome.services.util.Executor$Work.doWork
invocation took 50509
2014-05-28 11:07:04,310 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-2) INDEXED 50 objects in 1 batch(es) [50472 ms.]
2014-05-28 11:07:04,313 ERROR [ ome.services.util.ServiceHandler] (2-thread-2) Method interface ome.services.util.Executor$Work.doWork
invocation took 50481
2014-05-28 11:07:54,828 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) INDEXED 50 objects in 1 batch(es) [50495 ms.]
2014-05-28 11:07:54,830 ERROR [ ome.services.util.ServiceHandler] (2-thread-5) Method interface ome.services.util.Executor$Work.doWork
invocation took 50501
2014-05-28 11:08:45,314 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-4) INDEXED 50 objects in 1 batch(es) [50458 ms.]
2014-05-28 11:08:45,316 ERROR [ ome.services.util.ServiceHandler] (2-thread-4) Method interface ome.services.util.Executor$Work.doWork
invocation took 50466
2014-05-28 11:09:35,791 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-1) INDEXED 50 objects in 1 batch(es) [50452 ms.]
2014-05-28 11:09:35,794 ERROR [ ome.services.util.ServiceHandler] (2-thread-1) Method interface ome.services.util.Executor$Work.doWork
invocation took 50461
2014-05-28 11:10:26,293 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-2) INDEXED 50 objects in 1 batch(es) [50474 ms.]
2014-05-28 11:10:26,295 ERROR [ ome.services.util.ServiceHandler] (2-thread-2) Method interface ome.services.util.Executor$Work.doWork
invocation took 50480
2014-05-28 11:11:16,744 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) INDEXED 50 objects in 1 batch(es) [50428 ms.]
2014-05-28 11:11:16,746 ERROR [ ome.services.util.ServiceHandler] (2-thread-5) Method interface ome.services.util.Executor$Work.doWork
invocation took 50434
2014-05-28 11:12:07,184 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-3) INDEXED 50 objects in 1 batch(es) [50415 ms.]
2014-05-28 11:12:07,186 ERROR [ ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork
invocation took 50420
2014-05-28 11:12:57,632 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-1) INDEXED 50 objects in 1 batch(es) [50425 ms.]
2014-05-28 11:12:57,634 ERROR [ ome.services.util.ServiceHandler] (2-thread-1) Method interface ome.services.util.Executor$Work.doWork
invocation took 50430
2014-05-28 11:13:48,057 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-4) INDEXED 50 objects in 1 batch(es) [50403 ms.]
2014-05-28 11:13:48,060 ERROR [ ome.services.util.ServiceHandler] (2-thread-4) Method interface ome.services.util.Executor$Work.doWork
invocation took 50411
2014-05-28 11:14:38,481 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) INDEXED 50 objects in 1 batch(es) [50398 ms.]
2014-05-28 11:14:38,483 ERROR [ ome.services.util.ServiceHandler] (2-thread-5) Method interface ome.services.util.Executor$Work.doWork
invocation took 50403
2014-05-28 11:15:28,900 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-3) INDEXED 50 objects in 1 batch(es) [50393 ms.]
2014-05-28 11:15:28,903 ERROR [ ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork
invocation took 50400
2014-05-28 11:16:19,334 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-1) INDEXED 50 objects in 1 batch(es) [50410 ms.]
2014-05-28 11:16:19,336 ERROR [ ome.services.util.ServiceHandler] (2-thread-1) Method interface ome.services.util.Executor$Work.doWork
invocation took 50415
2014-05-28 11:17:09,759 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-4) INDEXED 50 objects in 1 batch(es) [50397 ms.]
2014-05-28 11:17:09,761 ERROR [ ome.services.util.ServiceHandler] (2-thread-4) Method interface ome.services.util.Executor$Work.doWork
invocation took 50403
2014-05-28 11:18:00,168 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-2) INDEXED 50 objects in 1 batch(es) [50391 ms.]
2014-05-28 11:18:00,170 ERROR [ ome.services.util.ServiceHandler] (2-thread-2) Method interface ome.services.util.Executor$Work.doWork
invocation took 50397
2014-05-28 11:18:50,602 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-3) INDEXED 50 objects in 1 batch(es) [50411 ms.]
2014-05-28 11:18:50,604 ERROR [ ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork
invocation took 50417
... and so on and on ....
Is this worrisome?
The time taken does not seem to trend upwards as it did before.
2014-06-01 13:15:42,615 ERROR [ ome.services.util.ServiceHandler] (2-thread-2) Method interface ome.services.util.Executor$Work.doWork invocation took 50460
2014-06-01 13:16:33,208 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) INDEXED 50 objects in 1 batch(es) [50576 ms.]
2014-06-01 13:16:33,210 ERROR [ ome.services.util.ServiceHandler] (2-thread-5) Method interface ome.services.util.Executor$Work.doWork invocation took 50580
2014-06-01 13:17:23,750 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-3) INDEXED 50 objects in 1 batch(es) [50519 ms.]
2014-06-01 13:17:23,751 ERROR [ ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork invocation took 50523
dsudar wrote:Hi Josh,
It has now been running since Wednesday and the Indexer-0.log still shows those >50000ms ERRORS every minute. Here are the last few...
psql omero -c "select 'At ' || current_timestamp(0) || ', Percent indexed: ' || trunc(((select count(*) from eventlog el, configuration c where el.id < cast(c.value as int) and (c.name like 'PersistentEventLogLoader%')) * 1.0) / (select count(*) from eventlog) * 100, 3) || '%';"
?column?
-----------------------------------------------------
At 2014-06-02 10:10:24+01, Percent indexed: 16.222%
(1 row)
I wouldn't be too worried about the above except that my searches still give mixed or no results...
?column?
-----------------------------------------------------
At 2014-06-02 12:38:52-07, Percent indexed: 99.836%
(1 row)
2014-06-02 04:24:43,123 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-3) INDEXED 50 objects in 1 batch(es) [50505 ms.]
2014-06-02 04:24:43,125 ERROR [ ome.services.util.ServiceHandler] (2-thread-3) Method interface ome.services.util.Executor$Work.doWork invocation took 50510
2014-06-02 04:25:33,756 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-4) INDEXED 50 objects in 1 batch(es) [50611 ms.]
2014-06-02 04:25:33,758 ERROR [ ome.services.util.ServiceHandler] (2-thread-4) Method interface ome.services.util.Executor$Work.doWork invocation took 50616
2014-06-02 04:26:13,198 WARN [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Null returned! Purging since cannot index ome.model.core.Image:Id_5 for ome.model.meta.EventLog:Id_1478104
2014-06-02 04:26:14,200 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Purged: class ome.model.core.Image:Id_5
2014-06-02 04:26:14,215 WARN [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Null returned! Purging since cannot index ome.model.core.Image:Id_7 for ome.model.meta.EventLog:Id_1478105
2014-06-02 04:26:15,216 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Purged: class ome.model.core.Image:Id_7
2014-06-02 04:26:15,232 WARN [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Null returned! Purging since cannot index ome.model.core.Image:Id_8 for ome.model.meta.EventLog:Id_1478106
2014-06-02 04:26:16,232 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Purged: class ome.model.core.Image:Id_8
2014-06-02 04:26:16,243 WARN [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Null returned! Purging since cannot index ome.model.core.Image:Id_17 for ome.model.meta.EventLog:Id_1478107
2014-06-02 04:26:17,244 INFO [ ome.services.fulltext.FullTextIndexer] (2-thread-5) Purged: class ome.model.core.Image:Id_17
Return to Installation and Deployment
Users browsing this forum: No registered users and 1 guest