Lucene index fails to load after upgrading to 2.2.0

Question

Lucene index fails to load after upgrading to 2.2.0

Opened this issue 4 years ago · 2 comments

After upgrading monitoring plugin 2.1.0 to 2.2.0 (Openfire 4.6.1, windows), the Lucene index fails to load, and the plugin fails to start. The monitoring plugin admin GUI is not visible.
The following errors are seen in the error.log of Openfire:

2021.01.11 09:18:50 org.jivesoftware.util.XMLProperties - Error reading XML properties
org.dom4j.DocumentException: Error on line 1 of document : Content is not allowed in prolog.
at org.dom4j.io.SAXReader.read(SAXReader.java:511) ~[dom4j-2.1.3.jar:?]
at org.dom4j.io.SAXReader.read(SAXReader.java:408) ~[dom4j-2.1.3.jar:?]
at org.jivesoftware.util.XMLProperties.buildDoc(XMLProperties.java:740) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.util.XMLProperties.(XMLProperties.java:163) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.util.XMLProperties.(XMLProperties.java:123) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.index.LuceneIndexer.loadPropertiesFile(LuceneIndexer.java:414) [monitoring-2.2.0.jar!/:?]
at org.jivesoftware.openfire.index.LuceneIndexer.start(LuceneIndexer.java:69) [monitoring-2.2.0.jar!/:?]
at org.picocontainer.defaults.DefaultLifecycleStrategy.start(DefaultLifecycleStrategy.java:46) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.InstantiatingComponentAdapter.start(InstantiatingComponentAdapter.java:164) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DecoratingComponentAdapter.start(DecoratingComponentAdapter.java:154) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.CachingComponentAdapter.start(CachingComponentAdapter.java:86) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultPicoContainer$OrderedComponentAdapterLifecycleManager.start(DefaultPicoContainer.java:663) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultPicoContainer.start(DefaultPicoContainer.java:464) [picocontainer-1.2.jar!/:?]
at org.jivesoftware.openfire.plugin.MonitoringPlugin.initializePlugin(MonitoringPlugin.java:205) [monitoring-2.2.0.jar!/:?]
at org.jivesoftware.openfire.container.PluginManager.loadPlugin(PluginManager.java:683) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.container.PluginMonitor$MonitorTask$4.call(PluginMonitor.java:375) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.container.PluginMonitor$MonitorTask$4.call(PluginMonitor.java:363) [xmppserver-4.6.1.jar:4.6.1]
at java.util.concurrent.FutureTask.run(Unknown Source) [?:1.8.0_231]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_231]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_231]
at java.lang.Thread.run(Unknown Source) [?:1.8.0_231]
Caused by: org.xml.sax.SAXParseException: Content is not allowed in prolog.
at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.fatalError(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLScanner.reportFatalError(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$PrologDriver.next(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(Unknown Source) ~[?:1.8.0_231]
at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source) ~[?:1.8.0_231]
at org.dom4j.io.SAXReader.read(SAXReader.java:494) ~[dom4j-2.1.3.jar:?]
... 20 more
2021.01.11 09:18:51 org.jivesoftware.openfire.archive.ArchiveIndexer[CONVERSATION] - An exception occurred while initializing the Lucene index that is expected to exist in: C:\Program Files\Openfire\monitoring\search
java.io.IOException: Error on line 1 of document : Content is not allowed in prolog.
at org.jivesoftware.util.XMLProperties.buildDoc(XMLProperties.java:744) ~[xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.util.XMLProperties.(XMLProperties.java:163) ~[xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.util.XMLProperties.(XMLProperties.java:123) ~[xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.index.LuceneIndexer.loadPropertiesFile(LuceneIndexer.java:414) ~[monitoring-2.2.0.jar!/:?]
at org.jivesoftware.openfire.index.LuceneIndexer.start(LuceneIndexer.java:69) [monitoring-2.2.0.jar!/:?]
at org.picocontainer.defaults.DefaultLifecycleStrategy.start(DefaultLifecycleStrategy.java:46) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.InstantiatingComponentAdapter.start(InstantiatingComponentAdapter.java:164) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DecoratingComponentAdapter.start(DecoratingComponentAdapter.java:154) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.CachingComponentAdapter.start(CachingComponentAdapter.java:86) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultPicoContainer$OrderedComponentAdapterLifecycleManager.start(DefaultPicoContainer.java:663) [picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultPicoContainer.start(DefaultPicoContainer.java:464) [picocontainer-1.2.jar!/:?]
at org.jivesoftware.openfire.plugin.MonitoringPlugin.initializePlugin(MonitoringPlugin.java:205) [monitoring-2.2.0.jar!/:?]
at org.jivesoftware.openfire.container.PluginManager.loadPlugin(PluginManager.java:683) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.container.PluginMonitor$MonitorTask$4.call(PluginMonitor.java:375) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.container.PluginMonitor$MonitorTask$4.call(PluginMonitor.java:363) [xmppserver-4.6.1.jar:4.6.1]
at java.util.concurrent.FutureTask.run(Unknown Source) [?:1.8.0_231]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_231]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_231]
at java.lang.Thread.run(Unknown Source) [?:1.8.0_231]
2021.01.11 09:18:51 org.jivesoftware.openfire.container.PluginManager - An exception occurred while loading plugin 'monitoring':
org.picocontainer.PicoLifecycleException: PicoLifecycleException: method 'public abstract void org.picocontainer.Startable.start()', instance 'org.jivesoftware.openfire.archive.ArchiveIndexer@4e8d2951, null
at org.picocontainer.monitors.DefaultComponentMonitor.lifecycleInvocationFailed(DefaultComponentMonitor.java:43) ~[picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultLifecycleStrategy.start(DefaultLifecycleStrategy.java:49) ~[picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.InstantiatingComponentAdapter.start(InstantiatingComponentAdapter.java:164) ~[picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DecoratingComponentAdapter.start(DecoratingComponentAdapter.java:154) ~[picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.CachingComponentAdapter.start(CachingComponentAdapter.java:86) ~[picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultPicoContainer$OrderedComponentAdapterLifecycleManager.start(DefaultPicoContainer.java:663) ~[picocontainer-1.2.jar!/:?]
at org.picocontainer.defaults.DefaultPicoContainer.start(DefaultPicoContainer.java:464) ~[picocontainer-1.2.jar!/:?]
at org.jivesoftware.openfire.plugin.MonitoringPlugin.initializePlugin(MonitoringPlugin.java:205) ~[monitoring-2.2.0.jar!/:?]
at org.jivesoftware.openfire.container.PluginManager.loadPlugin(PluginManager.java:683) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.container.PluginMonitor$MonitorTask$4.call(PluginMonitor.java:375) [xmppserver-4.6.1.jar:4.6.1]
at org.jivesoftware.openfire.container.PluginMonitor$MonitorTask$4.call(PluginMonitor.java:363) [xmppserver-4.6.1.jar:4.6.1]
at java.util.concurrent.FutureTask.run(Unknown Source) [?:1.8.0_231]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_231]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_231]
at java.lang.Thread.run(Unknown Source) [?:1.8.0_231]
Caused by: java.lang.NullPointerException
at org.jivesoftware.openfire.index.LuceneIndexer.getLastModified(LuceneIndexer.java:144) ~[monitoring-2.2.0.jar!/:?]
at org.jivesoftware.openfire.index.LuceneIndexer.start(LuceneIndexer.java:125) ~[monitoring-2.2.0.jar!/:?]
at org.picocontainer.defaults.DefaultLifecycleStrategy.start(DefaultLifecycleStrategy.java:46) ~[picocontainer-1.2.jar!/:?]
... 13 more

After removing the plugin, removing the monitoring directory (containing the index), the plugin could be reinstalled and started.

Answer 1 · 2021-01-21T13:00:46.000Z

I am unsure why and when the lucene index got corrupted. The server was part of a 2-server cluster. The other node did not have this problem when upgrading the plugin.

Answer 2 · 2021-12-19T22:49:10.000Z

I tried to reproduce the issue, but failed to. My attempts were on a macbook pro, with Openfire in a 3 node cluster running in docker. against the recent Openfire beta release.

Currently the automatic upgrade 2.1.0 -> 2.2.0 is not available, because a newer plugin version has been released since. I did automatic upgrades 2.1.0 -> 2.2.1 and manual upgrades 2.1.0 -> 2.2.0, both in OF 4.6.1 and the recent beta release. This resulted in several problems, more in the manual upgrades and somewhat less in the automatic upgrades. But those were all related to known issues like OF-2238 #115 #120 #170. At no point did I encounter a problem with Lucene indexing.

So I can't reproduce the issue yet. It may be related to my setup. But the problem may also have disappeared with the 2.2.1 release.

@fenuz What do you think? We could leave it at this. Or you could have another try on your end, and see whether the issue still exists now that 2.2.1 is the upgrade path.