iOS App Version 2.4.47 (but was happening on earlier versions too)
openHAB 3.3.0M3
Pi 4B
openhabian, updated all packages yesterday
Whenever I enter a command on the iOS app, I see this in the openhab log file. I have tried it with two different bindings (myq and mqtt) and it happens every time. I have found that after a while openHAB will become flaky (Astro binding triggers don’t fire for example), and I have to restart openHAB.
The commands are successful. Here is a recent example:
2022-04-12 11:28:57.772 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'MasterBathToiletFanMQTTThing_MasterBathToiletFanSwitch' received command ON
2022-04-12 11:28:57.782 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'MasterBathToiletFanMQTTThing_MasterBathToiletFanSwitch' predicted to become ON
2022-04-12 11:28:57.791 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'MasterBathToiletFanMQTTThing_MasterBathToiletFanSwitch' changed from OFF to ON
==> /var/log/openhab/openhab.log <==
2022-04-12 11:28:57.796 [INFO ] [rg.openhab.rule.MasterToiletFanTimer] - Master Toilet Fan Timer Turned On
==> /var/log/openhab/events.log <==
2022-04-12 11:28:57.921 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'GenericMQTTThing_MasterToiletFanSwitch' changed from OFF to ON
==> /var/log/openhab/openhab.log <==
2022-04-12 11:29:05.733 [WARN ] [ache.cxf.phase.PhaseInterceptorChain] - Interceptor for {http://internal.id.core.openhab.org/}UUIDResource has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: Could not send Message.
at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:67) ~[bundleFile:3.4.5]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) ~[bundleFile:3.4.5]
at org.apache.cxf.interceptor.OutgoingChainInterceptor.handleMessage(OutgoingChainInterceptor.java:90) ~[bundleFile:3.4.5]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:265) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:225) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:298) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doGet(AbstractHTTPServlet.java:222) ~[bundleFile:3.4.5]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) ~[bundleFile:3.1.0]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:273) ~[bundleFile:3.4.5]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[bundleFile:9.4.43.v20210629]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[bundleFile:?]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:602) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434) ~[bundleFile:9.4.43.v20210629]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:294) ~[bundleFile:?]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.43.v20210629]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:82) ~[bundleFile:?]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:386) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.43.v20210629]
at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.eclipse.jetty.io.EofException
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:829) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:915) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:987) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpOutput.close(HttpOutput.java:638) ~[bundleFile:9.4.43.v20210629]
at org.apache.cxf.transport.http.AbstractHTTPDestination$WrappedOutputStream.close(AbstractHTTPDestination.java:791) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.http.AbstractHTTPDestination$BackChannelConduit.close(AbstractHTTPDestination.java:722) ~[bundleFile:3.4.5]
at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63) ~[bundleFile:3.4.5]
... 48 more
Caused by: java.io.IOException: Broken pipe
at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:?]
at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:?]
at sun.nio.ch.IOUtil.write(IOUtil.java:182) ~[?:?]
at sun.nio.ch.IOUtil.write(IOUtil.java:130) ~[?:?]
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:493) ~[?:?]
at java.nio.channels.SocketChannel.write(SocketChannel.java:507) ~[?:?]
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:273) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:829) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:915) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:987) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpOutput.close(HttpOutput.java:638) ~[bundleFile:9.4.43.v20210629]
at org.apache.cxf.transport.http.AbstractHTTPDestination$WrappedOutputStream.close(AbstractHTTPDestination.java:791) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.http.AbstractHTTPDestination$BackChannelConduit.close(AbstractHTTPDestination.java:722) ~[bundleFile:3.4.5]
at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63) ~[bundleFile:3.4.5]
... 48 more
2022-04-12 11:29:05.743 [WARN ] [ache.cxf.phase.PhaseInterceptorChain] - Interceptor for {http://internal.id.core.openhab.org/}UUIDResource has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: XML_WRITE_EXC
at org.apache.cxf.jaxrs.interceptor.JAXRSDefaultFaultOutInterceptor.handleMessage(JAXRSDefaultFaultOutInterceptor.java:106) ~[bundleFile:3.4.5]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) ~[bundleFile:3.4.5]
at org.apache.cxf.interceptor.AbstractFaultChainInitiatorObserver.onMessage(AbstractFaultChainInitiatorObserver.java:112) ~[bundleFile:3.4.5]
at org.apache.cxf.phase.PhaseInterceptorChain.wrapExceptionAsFault(PhaseInterceptorChain.java:374) ~[bundleFile:3.4.5]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:332) ~[bundleFile:3.4.5]
at org.apache.cxf.interceptor.OutgoingChainInterceptor.handleMessage(OutgoingChainInterceptor.java:90) ~[bundleFile:3.4.5]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:265) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:225) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:298) ~[bundleFile:3.4.5]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doGet(AbstractHTTPServlet.java:222) ~[bundleFile:3.4.5]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) ~[bundleFile:3.1.0]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:273) ~[bundleFile:3.4.5]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[bundleFile:9.4.43.v20210629]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[bundleFile:?]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:602) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434) ~[bundleFile:9.4.43.v20210629]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:294) ~[bundleFile:?]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.43.v20210629]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:82) ~[bundleFile:?]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:386) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.43.v20210629]
at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: com.ctc.wstx.exc.WstxIOException: Closed
at com.ctc.wstx.sw.BaseStreamWriter.flush(BaseStreamWriter.java:262) ~[?:?]
at org.apache.cxf.jaxrs.interceptor.JAXRSDefaultFaultOutInterceptor.handleMessage(JAXRSDefaultFaultOutInterceptor.java:104) ~[bundleFile:3.4.5]
... 51 more
Caused by: org.eclipse.jetty.io.EofException: Closed
at org.eclipse.jetty.server.HttpOutput.checkWritable(HttpOutput.java:769) ~[bundleFile:9.4.43.v20210629]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:793) ~[bundleFile:9.4.43.v20210629]
at org.apache.cxf.io.AbstractWrappedOutputStream.write(AbstractWrappedOutputStream.java:51) ~[bundleFile:3.4.5]
at com.ctc.wstx.io.UTF8Writer.flush(UTF8Writer.java:100) ~[?:?]
at com.ctc.wstx.sw.BufferingXmlWriter.flush(BufferingXmlWriter.java:242) ~[?:?]
at com.ctc.wstx.sw.BaseStreamWriter.flush(BaseStreamWriter.java:260) ~[?:?]
at org.apache.cxf.jaxrs.interceptor.JAXRSDefaultFaultOutInterceptor.handleMessage(JAXRSDefaultFaultOutInterceptor.java:104) ~[bundleFile:3.4.5]
... 51 more
When I was first troubleshooting this and wasn’t sure what the problem was, someone suggested it was HTTP related. I’m seeing a similar error that appears to be related to the iCloud binding. Interceptor for {http://internal.id.core.openhab.org/}UUIDResource has thrown exception, unwinding now org.apache.cxf.interceptor.Fault: Could not send Message