Haufenweise LOG-Warnungen

[Micha-SHG]

Hallo zusammen,
ich werde im Moment im 1- bis 2-Minutentakt mit einer irre-langen Warnung in der LOG-Datei bombardiert. Ich habe keine Ahnung, was OpenHAB stört oder warum es stolpert. Alle Aufräumaktionen in den rules und in der sitemap haben keine Besserung gebracht. Kann mir bitte jemand von Euch einen Hinweis geben, was die Warnung bedeutet oder wie ich der Ursache auf die Schliche kommen kann?

Ich setze OpenHAB 2.4 auf einem Raspi ein.

Code: Alles auswählen

2018-12-30 00:44:47.180 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /rest/sitemaps/myhome/myhome
javax.servlet.ServletException: javax.servlet.ServletException: A MultiException has 1 exceptions.  They are:
1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_680,681,21602148) has been shut down
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:88) ~[?:?]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.Server.handle(Server.java:531) ~[84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [84:org.eclipse.jetty.server:9.4.11.v20180605]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [75:org.eclipse.jetty.io:9.4.11.v20180605]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [75:org.eclipse.jetty.io:9.4.11.v20180605]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [75:org.eclipse.jetty.io:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) [87:org.eclipse.jetty.util:9.4.11.v20180605]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: javax.servlet.ServletException: A MultiException has 1 exceptions.  They are:
1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_680,681,21602148) has been shut down
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489) ~[?:?]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) ~[?:?]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) ~[?:?]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) ~[?:?]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) ~[?:?]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) ~[?:?]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) ~[?:?]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) ~[?:?]
	... 15 more
Caused by: org.glassfish.hk2.api.MultiException: A MultiException has 1 exceptions.  They are:
1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_680,681,21602148) has been shut down
	at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:106) ~[?:?]
	at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173) ~[?:?]
	at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526) ~[?:?]
	at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532) ~[?:?]
	at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549) ~[?:?]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319) ~[?:?]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) ~[?:?]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) ~[?:?]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) ~[?:?]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) ~[?:?]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) ~[?:?]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) ~[?:?]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) ~[?:?]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) ~[?:?]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) ~[?:?]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) ~[?:?]
	... 15 more
Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_680,681,21602148) has been shut down
	at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2288) ~[?:?]
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandleImpl(ServiceLocatorImpl.java:629) ~[?:?]
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:622) ~[?:?]
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:640) ~[?:?]
	at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:103) ~[?:?]
	at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173) ~[?:?]
	at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526) ~[?:?]
	at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532) ~[?:?]
	at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549) ~[?:?]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319) ~[?:?]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) ~[?:?]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) ~[?:?]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) ~[?:?]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) ~[?:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) ~[?:?]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) ~[?:?]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) ~[?:?]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) ~[?:?]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) ~[?:?]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) ~[?:?]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) ~[?:?]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) ~[?:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) ~[?:?]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) ~[?:?]
	... 15 more

[sihui]

oder wie ich der Ursache auf die Schliche kommen kann?

Bei solchen Fehlern würde ich erst einmal cache und tmp Ordner leeren und openHAB neu starten.

https://community.openhab.org/t/clear-the-cache/36424

[Micha-SHG]

Danke schon einmal für den ersten Hinweis, aber "Cache und tmp-Ordner leeren, openHAB neustarten" hat leider keine Besserung gebracht, es hagelt weiterhin die o.g. Warnhinweise in der LOG.
Dafür habe ich eine neue Beobachtung gemacht: Nach dem Neustart kamen erst einmal keine Warnungen, erst als ich die Sitemap im Edge-Browser bzw. in der openHAB-Adroid-App geöffnet habe, kamen die Meldungen. Schließe ich Browser-Karteikarte bzw. die Adroid-App so verstummen auch die Warnungen in der LOG. Dieses Spielchen ist reproduzierbar.
Daraufhin habe ich meine myhome.sitemap auf ein einzelnes item reduziert, aber die Warnungen kommen trotzdem. Es ist auch egal welches item ich nehme.
An der Sitemap scheint es demnach ja nicht zu liegen.
Hat noch jemand eine Idee?
An alle in der community schon einmal einen Guten Rutsch ins nächste Jahr
Michael

[sihui]

Hat noch jemand eine Idee?

Hast du Einträge in der addons.cfg gemacht? Falls ja, überprüfe mal die Korrektheit der Einträge, ggf. addons.config löschen und openHAB neu starten:

https://community.openhab.org/t/after-u ... tion/61567

[Micha-SHG]

Danke Sihui, aber auch das hat nichts gebracht. Mittlerweile ist mein System völlig zu Bruch gegangen (irgendeiner meiner Test- und Optimierungsversuche war wohl kontraproduktiv) und startet noch nicht einmal mehr. Somit habe ich meine Datensicherung von vor dem Update auf 2.4 wieder eingespielt.
Nun läuft alles wieder einwandfrei, auch ohne die minütlichen Warnhinweise im LOG-file.
Ich werde jetzt noch einmal in kleinen Schritten versuchen, mein openHAB zu verschlanken (alle alten Testitems, -rules usw. rausschmeißen) und dann noch einmal auf 2.4 updaten.
Beim Thema "Aufräumen" möchte ich noch einmal auf Deinen Hinweis zur addons.cfg zurückkommen: Ich hatte mal gelesen, dass in der addons.cfg alle bindings aufgelistet sein sollten. Ist das noch richtig oder stammt das evtl. aus früheren Versionen? In meiner cfg steht derzeit nur:

Code: Alles auswählen

binding = astro, exec, gpio1, mqtt1, sonos, yahoowether, http1

Viele Grüße
Michael

[sihui]

Ich hatte mal gelesen, dass in der addons.cfg alle bindings aufgelistet sein sollten. Ist das noch richtig oder stammt das evtl. aus früheren Versionen? In meiner cfg steht derzeit nur:

Code: Alles auswählen

binding = astro, exec, gpio1, mqtt1, sonos, yahoowether, http1

Es gibt dabei ein entweder/oder: Entweder du installierst deine Bindings per PaperUI oder du installierst deine Bindings per addons.cfg.
Dabei hat addons.cfg Vorrang: wenn du ein einziges Binding über addons.cfg installierst kannst du keine Bindings mehr über PaperUI installieren.
Falls du dich für addons.cfg entscheidest solltest du die Leerzeichen weglassen (bin mir nicht mehr ganz sicher, aber da gab es mal was ...)

[udo1toni]

Um es etwas zu präzisieren: Sobald in addons.cfg irgendwelche Parameter gesetzt sind, wird openHAB alle Parameter aus addons.cfg beim Start von openHAB auswerten und das System entsprechend konfigurieren.
Man kann also sehr wohl Addons über Paper UI installieren, openHAB wird sie aber beim nächsten Start von openHAB wieder deinstallieren.
Das kann man durchaus nutzen, z.B. um einige Bindings testweise einzurichten (über Paper UI). openHAB räumt beim nächsten Start selbst auf
Die Bindings, welche man behalten möchte, trägt man vor dem nächsten Start in addons.cfg ein.
Ein weiterer Vorteil besteht darin, dass man ausschließlich den Zweig /etc/openhab2/ sichern muss, sofern man auch den Rest über Textdateien konfiguriert hat. openHAB zieht beim Start das komplette System aus diesem Zweig hoch, auch, wenn man das System vorher komplett neu installiert hat. Natürlich verliert man dann persistente Daten und spezielle Anpassungen (z.B. Logging-Konfiguration), kann aber sicher sein, dass das System quasi im Auslieferungszustand ist.

[Micha-SHG]

Wow, Danke. Das erklärt, warum neulich ein Binding plötzlich nicht mehr vorhanden war (nach dem Installieren des Bindings nicht in addon.cfg eingetragen, Tage später den Raspi neu gestartet -> Binding weg).