Domino 11.0.1FP1 wirft Java-Fehler

[Flachmann]

Hallo,

ich hatte gerade mal über die Domino Console auf unseren Domino 11.0.1FP1 Server (unter Windows) geschaut. Dort taucht alle paar Minuten diese Java-Fehlermeldung auf. Im Log und in der Server Console des Admin-Clients wird das nicht gezeigt, darum war es eher Zufall, dass ich das bemerkte.

Code

Nov 26, 2020 6:32:42 PM org.apache.tika.config.InitializableProblemHandler$3 handleInitializableProblem
WARNUNG: J2KImageReader not loaded. JPEG2000 files will not be processed.
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.

Nov 26, 2020 6:32:42 PM org.apache.tika.config.InitializableProblemHandler$3 handleInitializableProblem
WARNUNG: org.xerial's sqlite-jdbc is not loaded.
Please provide the jar on your classpath to parse sqlite files.
See tika-parsers/pom.xml for the correct version.
org.apache.cxf.service.factory.ServiceConstructionException
	at org.apache.cxf.jaxrs.JAXRSServerFactoryBean.create(JAXRSServerFactoryBean.java:225)
	at org.apache.tika.server.TikaServerCli.executeLegacy(TikaServerCli.java:333)
	at org.apache.tika.server.TikaServerCli.execute(TikaServerCli.java:158)
	at org.apache.tika.server.TikaServerCli.main(TikaServerCli.java:127)
Caused by: org.apache.cxf.interceptor.Fault: Could not start Jetty server on port 9.998: Address already in use: bind
	at org.apache.cxf.transport.http_jetty.JettyHTTPServerEngine.addServant(JettyHTTPServerEngine.java:484)
	at org.apache.cxf.transport.http_jetty.JettyHTTPDestination.activate(JettyHTTPDestination.java:187)
	at org.apache.cxf.transport.AbstractObservable.setMessageObserver(AbstractObservable.java:53)
	at org.apache.cxf.binding.AbstractBindingFactory.addListener(AbstractBindingFactory.java:95)
	at org.apache.cxf.jaxrs.JAXRSBindingFactory.addListener(JAXRSBindingFactory.java:88)
	at org.apache.cxf.endpoint.ServerImpl.start(ServerImpl.java:132)
	at org.apache.cxf.jaxrs.JAXRSServerFactoryBean.create(JAXRSServerFactoryBean.java:212)
	... 3 more
Caused by: java.net.BindException: Address already in use: bind
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:433)
	at sun.nio.ch.Net.bind(Net.java:425)
	at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
	at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:85)
	at org.eclipse.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:339)
	at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:307)
	at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
	at org.eclipse.jetty.server.ServerConnector.doStart(ServerConnector.java:235)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
	at org.eclipse.jetty.server.Server.doStart(Server.java:395)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
	at org.apache.cxf.transport.http_jetty.JettyHTTPServerEngine.addServant(JettyHTTPServerEngine.java:473)
	... 9 more

Tika ist ja der neue Volltext-Indexer. Aber was bedeutet diese Fehlermeldung. Klar, da wird eine Java-Task einen Fehler, aber was bedeutet das für Domino?

Auf einer zweiten  Maschine:

Code

JVMDUMP010I Speicherauszug von System in C:\Program Files\HCL\Domino\core.20201126.185138.6756.0001.dmp geschrieben
JVMDUMP032I JVM forderte als Antwort auf ein Ereignis einen Speicherauszug von Heap mit "C:\Program Files\HCL\Domino\heapdump.20201126.185138.6756.0002.phd" an
JVMDUMP010I Speicherauszug von Heap in C:\Program Files\HCL\Domino\heapdump.20201126.185138.6756.0002.phd geschrieben
JVMDUMP032I JVM forderte als Antwort auf ein Ereignis einen Speicherauszug von Java mit "C:\Program Files\HCL\Domino\javacore.20201126.185138.6756.0003.txt" an
JVMDUMP010I Speicherauszug von Java in C:\Program Files\HCL\Domino\javacore.20201126.185138.6756.0003.txt geschrieben
JVMDUMP032I JVM forderte als Antwort auf ein Ereignis einen Speicherauszug von Snap mit "C:\Program Files\HCL\Domino\Snap.20201126.185138.6756.0004.trc" an
JVMDUMP010I Speicherauszug von Snap in C:\Program Files\HCL\Domino\Snap.20201126.185138.6756.0004.trc geschrieben
JVMDUMP013I Speicherauszugsereignis "systhrow", Detail "java/lang/OutOfMemoryError" wurde verarbeitet.
org.apache.cxf.service.factory.ServiceConstructionException
	at org.apache.cxf.jaxrs.JAXRSServerFactoryBean.create(JAXRSServerFactoryBean.java:225)
	at org.apache.tika.server.TikaServerCli.executeLegacy(TikaServerCli.java:333)
	at org.apache.tika.server.TikaServerCli.execute(TikaServerCli.java:158)
	at org.apache.tika.server.TikaServerCli.main(TikaServerCli.java:127)
Caused by: org.apache.cxf.interceptor.Fault: Could not start Jetty server on port 9.998: Multiple exceptions
	at org.apache.cxf.transport.http_jetty.JettyHTTPServerEngine.addServant(JettyHTTPServerEngine.java:484)
	at org.apache.cxf.transport.http_jetty.JettyHTTPDestination.activate(JettyHTTPDestination.java:187)
	at org.apache.cxf.transport.AbstractObservable.setMessageObserver(AbstractObservable.java:53)
	at org.apache.cxf.binding.AbstractBindingFactory.addListener(AbstractBindingFactory.java:95)
	at org.apache.cxf.jaxrs.JAXRSBindingFactory.addListener(JAXRSBindingFactory.java:88)
	at org.apache.cxf.endpoint.ServerImpl.start(ServerImpl.java:132)
	at org.apache.cxf.jaxrs.JAXRSServerFactoryBean.create(JAXRSServerFactoryBean.java:212)
	... 3 more
Caused by: MultiException[java.lang.OutOfMemoryError: Threaderstellung ist fehlgeschlagen: retVal -1073741830, errno 22, java.net.BindException: Address already in use: bind]
	at org.eclipse.jetty.util.MultiException.ifExceptionThrow(MultiException.java:124)
	at org.eclipse.jetty.server.Server.doStart(Server.java:406)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
	at org.apache.cxf.transport.http_jetty.JettyHTTPServerEngine.addServant(JettyHTTPServerEngine.java:473)
	... 9 more
	Suppressed: java.lang.OutOfMemoryError: Threaderstellung ist fehlgeschlagen: retVal -1073741830, errno 22
		at java.lang.Thread.startImpl(Native Method)
		at java.lang.Thread.start(Thread.java:991)
		at org.eclipse.jetty.util.thread.QueuedThreadPool.startThreads(QueuedThreadPool.java:543)
		at org.eclipse.jetty.util.thread.QueuedThreadPool.doStart(QueuedThreadPool.java:146)
		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
		at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:138)
		at org.eclipse.jetty.server.Server.start(Server.java:416)
		at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:117)
		at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:113)
		at org.eclipse.jetty.server.Server.doStart(Server.java:383)
		... 11 more
	Suppressed: java.net.BindException: Address already in use: bind
		at sun.nio.ch.Net.bind0(Native Method)
		at sun.nio.ch.Net.bind(Net.java:433)
		at sun.nio.ch.Net.bind(Net.java:425)
		at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
		at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:85)
		at org.eclipse.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:339)
		at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:307)
		at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
		at org.eclipse.jetty.server.ServerConnector.doStart(ServerConnector.java:235)
		at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
		at org.eclipse.jetty.server.Server.doStart(Server.java:395)
		... 11 more
	[CIRCULAR REFERENCE:java.lang.OutOfMemoryError]

Es gibt auch einen Haufen Dump-Dateien. 

Hat da jemand eine Idee? Danke!

[eknori]

Steht doch in der Fehlermeldung

Code

Could not start Jetty server on port 9.998: Address already in use: bind

Irgendwas rödelt da auf dem port 9998 rum.

[Flachmann]

Code

Could not start Jetty server on port 9.998: Address already in use: bind

Irgendwas rödelt da auf dem port 9998 rum.

Wow, das ging schnell.    Wer lesen kann...

Stimmt, 9998 ist blockiert. Und zwar von der "OpenJDK Platform binary" java.exe unter HCL\Domino\jvm\bin. D.h. Domino ist selbst das Problem und blockiert sich selbst den Port?!

Ich versuche es dann mal mit Port 9997, der ist noch frei (https://help.hcltechsw.com/domino/10.0.1/admn_attachment_indexing.html). Dieser Port wird bei mir als frei angezeigt.

[Flachmann]

Wie zu erwarten war: das Problem ist Domino-intern:

Code

Caused by: org.apache.cxf.service.factory.ServiceConstructionExceptionorg.apache.cxf.interceptor.Fault: Could not start Jetty server on port 9.997: Address already in use: bind

Der zuvor freie Port ist nun belegt.

Nach einem kompletten Server-Neustart ist nun Port 9998 frei, dafür 9997 belegt. Das Ändern des Ports ist also nicht der Weisheit letzter Schluss.  

Ich denke, dass dieses ganze Tika-VT-Thema noch nicht richtig ausgegoren ist.

[eknori]

bei mir funktioniert es einwandfrei.

Sieht so aus, als ob TIKA bei Dir 2x gestartet wird.

[Flachmann]

Ich hatte in mehreren DBs den VT-Index erstellen lassen, um die neuen Tika-Funktionen zu nutzen "gefiltert". Dabei kommt es zu zahlreichen Fehlern, die weder in log.nsf noch im Admin Clients Server Console protokolliert werden, sondern nur auf dieser separaten Java "Server Console" zu sehen sind. Vielleicht müsste ich irgendwelche LogLevel höher setzen...  

Ich schaue nächste Woche mal, ob ich die Fehler noch irgendwo finde. Auf jeden Fall hingen alle Fehler mit Attachments zusammen. Wenn man ohne Attachments indiziert, ist alles OK.

Dieser "doppelte" Start passiert, wenn sich die Tika-Engine aufhängt. Domino geht dann wohl zur nächsten DB über, versucht zu indizieren und stolpert über die abgestürzte Task.

Ich habe noch diesen Artikel gefunden und werde das dann auch mal probieren. Das könnte die Ursache sein:
http://blog.nashcom.de/nashcomblog.nsf/dx/domino-10-attachment-indexing-with-apache-tika.htm