I'm upgrading an Alfresco 4.0 to an Alfresco 4.2. All went well, except for the lucene indexes. The reindexing starts, but ends in a, so it seems, indefinete "Index cleaner running". I got this message by raising the loglevels for lucene indexing. This is all happening in the startup sequence, so Alfresco is not starting. When i switch the index.subsystem.name to "solr" or "noindex", Alfresco is starting smoothly.
For all attempts i start with a non-existing directory "lucene-indexes" in alf_data. On one attempt, it's only creating subdirectories "users" and locks", on other attempts, it creates them all. It seems a bit random.
There was one time i did get a complete set of new indexes for this contentstore/database, but now it wont work. What can be wrong? Does anyone have experience with this?
At my last attempt, there is one error logged. Not a lot later it stops doing except for logging "index cleaner running"
below a snippet of the logs (the tail)
Thanks for any help.
Koen
2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] Index cleaner running ... 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] Deleting no longer referenced a393ae15-87c2-4a75-8574-d1a83d1e3391 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] ... queued delete for a393ae15-87c2-4a75-8574-d1a83d1e3391 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] ... Id = a393ae15-87c2-4a75-8574-d1a83d1e3391 Invalid = 0 invalid = true closed=true 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] Waiting for READ lock - indexThread8 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] ...GOT READ LOCK - indexThread8 - in 2.445E-4 ms 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] RELEASED READ LOCK - indexThread8 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] Expunging a393ae15-87c2-4a75-8574-d1a83d1e3391 remaining 1 2014-06-12 18:55:50,873 DEBUG [lucene.index.IndexInfo] [indexThread8] ... Id = a393ae15-87c2-4a75-8574-d1a83d1e3391 Invalid = 0 invalid = true closed=true 2014-06-12 18:55:51,248 ERROR [node.ibatis.NodeDAOImpl$MSSQL] [indexTrackerThread4] ALF-12358: Deleted node - removed child assoc: 226227 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced d9230dc6-af01-43ab-b69c-db729723c422 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for d9230dc6-af01-43ab-b69c-db729723c422 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 3.073E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced cce63ed2-637b-466f-9ec0-5fe16ab077eb 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for cce63ed2-637b-466f-9ec0-5fe16ab077eb 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.375E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced 4061f942-ad1b-4e4b-b4b8-475f459c822f 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for 4061f942-ad1b-4e4b-b4b8-475f459c822f 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.375E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced 969ed486-4374-4554-822c-beccfab44542 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for 969ed486-4374-4554-822c-beccfab44542 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.095E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced bf479c4b-d905-4d9f-988e-bddcc3a48c1e 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for bf479c4b-d905-4d9f-988e-bddcc3a48c1e 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.095E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced f7a94387-f283-4424-8b3d-56818ef3c769 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for f7a94387-f283-4424-8b3d-56818ef3c769 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced cc224d15-0d18-45f7-aa03-a9c3ae3dec8e 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for cc224d15-0d18-45f7-aa03-a9c3ae3dec8e 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced 623ec896-5e37-4bb8-ba01-cb714bc81f2d 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for 623ec896-5e37-4bb8-ba01-cb714bc81f2d 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced e366e001-6f93-4efe-854e-07625942b8bb 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for e366e001-6f93-4efe-854e-07625942b8bb 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced f2c8f05e-a434-4ac7-9081-4eabffe52316 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for f2c8f05e-a434-4ac7-9081-4eabffe52316 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.025E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced 44bee16a-ad02-4de0-a052-0f51950ffa69 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for 44bee16a-ad02-4de0-a052-0f51950ffa69 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced b9ffe899-c794-4738-a787-2158a7d578a4 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for b9ffe899-c794-4738-a787-2158a7d578a4 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced b1c01cce-5fc9-48bd-a52a-67c4e02e1c35 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for b1c01cce-5fc9-48bd-a52a-67c4e02e1c35 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Deleting no longer referenced ad0dae67-237f-454b-ba92-554560be2afa 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... queued delete for ad0dae67-237f-454b-ba92-554560be2afa 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Waiting for READ lock - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ...GOT READ LOCK - indexThread7 - in 2.165E-4 ms 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] RELEASED READ LOCK - indexThread7 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging d9230dc6-af01-43ab-b69c-db729723c422 remaining 14 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread10] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread10] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread10] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread10] Index cleaner running ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging cce63ed2-637b-466f-9ec0-5fe16ab077eb remaining 13 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging 4061f942-ad1b-4e4b-b4b8-475f459c822f remaining 12 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging 969ed486-4374-4554-822c-beccfab44542 remaining 11 2014-06-12 18:55:52,153 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging bf479c4b-d905-4d9f-988e-bddcc3a48c1e remaining 10 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging f7a94387-f283-4424-8b3d-56818ef3c769 remaining 9 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging cc224d15-0d18-45f7-aa03-a9c3ae3dec8e remaining 8 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging 623ec896-5e37-4bb8-ba01-cb714bc81f2d remaining 7 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging e366e001-6f93-4efe-854e-07625942b8bb remaining 6 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging f2c8f05e-a434-4ac7-9081-4eabffe52316 remaining 5 2014-06-12 18:55:52,169 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging 44bee16a-ad02-4de0-a052-0f51950ffa69 remaining 4 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging b9ffe899-c794-4738-a787-2158a7d578a4 remaining 3 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging b1c01cce-5fc9-48bd-a52a-67c4e02e1c35 remaining 2 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] Expunging ad0dae67-237f-454b-ba92-554560be2afa remaining 1 2014-06-12 18:55:52,184 DEBUG [lucene.index.IndexInfo] [indexThread7] ... 2014-06-12 18:56:12,179 DEBUG [lucene.index.IndexInfo] [indexThread4] Index cleaner running ... 2014-06-12 18:56:12,179 DEBUG [lucene.index.IndexInfo] [indexThread4] Index cleaner running ... 2014-06-12 18:56:12,179 DEBUG [lucene.index.IndexInfo] [indexThread4] Index cleaner running ... etc etc etc
