Interceptor for {http://internal.id.core.openhab.org/}UUIDResource has thrown exception, unwinding now org.apache.cxf.interceptor.Fault: Could not send Message

BigGeorgeTx · April 7, 2022, 12:28am

Running openHAB 3.3.0M3, on a Pi4B running openhabian, but I saw the same behavior in earlier versions.

This will happen a few times then some things in openHAB (like Astro triggers) stop working. If I restart openHAB (systemctl restart openhab) everything works for a while, but usually within a day, it starts happening again.

I’m not sure where to look or what to log to troubleshoot this, and would appreciate any suggestions.

2022-04-06 17:50:40.762 [INFO ] [penhab.core.model.script.iPhone Home] - George's iPhone is away from Springhome.
2022-04-06 17:50:40.787 [INFO ] [enhab.core.model.script.PRESENCE.log] - George is away, setting anti-flapping timer
2022-04-06 17:50:40.789 [INFO ] [g.openhab.core.model.script.Presence] - gGeorgePresence=OFF, George PresentAllDevices=OFF
2022-04-06 17:52:13.938 [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-06 17:52:13.949 [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
2022-04-06 17:52:38.378 [INFO ] [enhab.core.model.script.PRESENCE.log] - Timer is running but group and proxy George are the same, cancelling timer
2022-04-06 17:52:38.385 [INFO ] [enhab.core.model.script.PRESENCE.log] - George came home, setting presence to ON
2022

The rule that ran just before this sent the specified message to the log:

rule "Start Conflict Timer if change to conflicted"

when Item gGeorgePresence changed or Item GeorgePresentAllDevices changed

then if (gGeorgePresence.state != GeorgePresentAllDevices.state) {George_Presence_Conflict_Timer.sendCommand(ON)}

else {George_Presence_Conflict_Timer.postUpdate(OFF)}

logInfo("Presence", "gGeorgePresence= "+ gGeorgePresence.state + ", George PresentAllDevices= " +GeorgePresentAllDevices.state)

end

As does the rule that runs right after it:

rule "George presence sensor group updated"
when
        Item gGeorgePresence changed
then

    if(Presence_George_Timer.state == ON && gGeorgePresence.state == Presence_George.state) {
        logInfo(logName, "Timer is running but group and proxy George are the same, cancelling timer")
        Presence_George_Timer.postUpdate(OFF)
    }
    else if(gGeorgePresence.state == Presence_George.state) {
        logInfo(logName, "No timer and both group and proxy George are the same, nothing to do")
        return;
    }

    if(gGeorgePresence.state == OFF) {
        logInfo(logName, "George is away, setting anti-flapping timer")
        Presence_George_Timer.sendCommand(ON)
    }
    else if(gGeorgePresence.state == ON) {
        logInfo(logName, "George came home, setting presence to ON")
        Presence_George.sendCommand(ON)
        Recent_Short_Term_Presence_George.sendCommand(ON) //testing
        Recent_Short_Term_Presence_George_Timer.sendCommand(ON) //testing
        George_Recently_Present_But_Now_Absent.sendCommand(OFF)
    }

end

BigGeorgeTx · April 8, 2022, 12:39am

Happened again today.

2022-04-07 16:56:30.731 [WARN ] [penhab.rule.iCloudLocationHeartbeats] - ICloud Location Update for: GeorgesiPhoneiPhone13Pro_Location.  Restarting iCloud connection timer
2022-04-07 16:59:43.427 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: OFFKathleen Presence groupON
2022-04-07 17:00:11.800 [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-07 17:00:11.925 [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
2022-04-07 17:00:44.115 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: ONKathleen Presence groupON
2022-04-07 17:00:55.463 [INFO ] [g.openhab.core.model.script.Presence] - gGeorgePresence= ON, George PresentAllDevices= OFF
2022-04-07 17:00:55.466 [INFO ] [enhab.core.model.script.PRESENCE.log] - George came home, setting presence to ON
2022-04-07 17:00:55.507 [INFO ] [enhab.core.model.script.PRESENCE.log] - George Presence changed from off to on, run arrival routine
2022-04-07 17:00:55.516 [INFO ] [nhab.core.model.script.Notifications] - Sending notification via email
2022-04-07 17:01:31.916 [WARN ] [penhab.rule.iCloudLocationHeartbeats] - ICloud Location Update for: KathleeniPhoneiPhone13_Location.  Restarting iCloud connection timer
2022

splatch · April 8, 2022, 8:57am

Errors you see are warnings caused by client or server connection closure. These are server side messages where OH rest endpoints can not flush their data to the client.

BigGeorgeTx · April 9, 2022, 3:51pm

Thanks for the response. I don’t know enough fully appreciate what you told me. Is there anything I can do about it?

splatch · April 9, 2022, 9:07pm

It is error reported by backend so look at things which call it. Do you have some shell scripts which interact with openHAB? Is your installation HTTP interface is used by tools other than openHAB UI?

BigGeorgeTx · April 10, 2022, 1:04am

Thanks for the explanation. I don’t think I have any shell scripts. I don’t think is anything else on my Pi that uses the HTTP interface.

I think it is happening when I use the openhab IOS app. At least today, I noticed a strong correlation between when I used the openhab IOS app to close the garage door and when I had this type of error. I will look through past logs and, if I see that correlation I will report it. I want to be careful, as I have observed some users are too quick to blame a binding they think is causing their problems, and some of the developers are easily upset when they think someone has maligned their work.

splatch · April 10, 2022, 10:15am

Mobile app uses http interface. It could be that mobile cuts http connection for some reason. Look for ways to get some diagnostic information for it.
If you use openhabcloud then it could be related to recent stability issues. You can look for posts about it to apply fixes.

BigGeorgeTx · April 11, 2022, 1:29am

Thanks. I’m conducting an experiment. I won’t enter any commands in the IOS app for a few days. If they doesn’t recur, then I will try entering commands and see if I can trigger it.

I think it may be happening when I come home and the iPhone is switching between from the 5G or LTE mobile network to my home network wifi. When I’m on my bike or walking, I will use the openhab IOS app to open the garage door. Although I didn’t see it at first in the logs because there are other events happening closer to the error, I think that generally there is a garage door opening around the time the error occurs. The command executes, at least most of the time.

I do use openhabcloud for the IOS app (and Alexa) connection. I looked for a relevant post on the openhabcloud stability, but wasn’t successful in finding anything. If my hypothesis is validated by the above experiment, I will start a new post focused on those areas that will hopefully attract the attention of the maintainers.

thanks again for all of your helpful suggestions.

BigGeorgeTx · April 11, 2022, 2:59pm

Similar error, but different trigger:

2022-04-10 20:06:57.322 [WARN ] [l.handler.ICloudAccountBridgeHandler] - Unable to refresh device data
java.io.IOException: java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@961105::DecryptedEndPoint@66bd22{l=/192.168.1.89:39364,r=fmipmobile.icloud.com/17.248.241.139:443,OPEN,fill=-,flush=-,to=300098/0}
	at org.openhab.core.io.net.http.HttpUtil.executeUrlAndGetReponse(HttpUtil.java:260) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrl(HttpUtil.java:155) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrl(HttpUtil.java:130) ~[?:?]
	at org.openhab.core.io.net.http.HttpRequestBuilder.getContentAsString(HttpRequestBuilder.java:135) ~[?:?]
	at org.openhab.binding.icloud.internal.ICloudConnection.callApi(ICloudConnection.java:90) ~[?:?]
	at org.openhab.binding.icloud.internal.ICloudConnection.requestDeviceStatusJSON(ICloudConnection.java:71) ~[?:?]
	at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.lambda$0(ICloudAccountBridgeHandler.java:94) ~[?:?]
	at org.openhab.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:101) ~[?:?]
	at org.openhab.core.cache.ExpiringCache.getValue(ExpiringCache.java:72) ~[?:?]
	at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.refreshData(ICloudAccountBridgeHandler.java:161) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@961105::DecryptedEndPoint@66bd22{l=/192.168.1.89:39364,r=fmipmobile.icloud.com/17.248.241.139:443,OPEN,fill=-,flush=-,to=300098/0}
	at org.eclipse.jetty.client.util.FutureResponseListener.getResult(FutureResponseListener.java:118) ~[?:?]
	at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:101) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:730) ~[?:?]
	at org.openhab.core.io.net.http.HttpUtil.executeUrlAndGetReponse(HttpUtil.java:251) ~[?:?]
	... 15 more
Caused by: java.io.EOFException: HttpConnectionOverHTTP@961105::DecryptedEndPoint@66bd22{l=/192.168.1.89:39364,r=fmipmobile.icloud.com/17.248.241.139:443,OPEN,fill=-,flush=-,to=300098/0}
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.earlyEOF(HttpReceiverOverHTTP.java:376) ~[?:?]
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1614) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.shutdown(HttpReceiverOverHTTP.java:259) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:181) ~[?:?]
	at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:79) ~[?:?]
	at org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:131) ~[?:?]
	at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:172) ~[?:?]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[?:?]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410) ~[?:?]
	at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164) ~[?:?]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[?:?]
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[?:?]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[?:?]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[?:?]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[?:?]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[?:?]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:386) ~[?:?]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[?:?]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[?:?]
	... 1 more
2022-04-10 20:07:13.892 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: ONKathleen Presence groupON
2022-04-10 20:07:58.954 [INFO ] [a.internal.handler.TuyaDeviceHandler] - Configuring IP address 'DeviceInfo{ip='192.168.1.228', version='3.3'}' for thing 'tuya:tuyaDevice:601867532462ab3a32c4'.
2022-04-10 20:08:19.413 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: OFFKathleen Presence groupON
2022-04-10 20:09:19.933 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: ONKathleen Presence groupON
2022-04-10 20:10:29.536 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: OFFKathleen Presence groupON
2022-04-10 20:11:34.183 [INFO ] [e.KathleenPresenceConflictTimerStart] - Kathleen Presence conflict with all devices: ONKathleen Presence groupON
2022-04-10 20:11:58.295 [WARN ] [penhab.rule.iCloudLocationHeartbeats] - ICloud Location Update for: KathleeniPhoneiPhone13_Location.  Restarting iCloud connection timer
2022-04-10 20:11:58.307 [WARN ] [penhab.rule.iCloudLocationHeartbeats] - ICloud Location Update for: GeorgesiPhoneiPhone13Pro_Location.  Restarting iCloud connection timer
2022-04-10 20:14:22.927 [INFO ] [g.openhab.core.model.script.Presence] - gGeorgePresence= ON, George PresentAllDevices= OFF
2022-04-10 20:15:07.838 [WARN ] [g.icalendar.internal.handler.PullJob] - Download of calendar failed with ExecutionException: HttpConnectionOverHTTP@567e2b::DecryptedEndPoint@f8f5c9{l=/192.168.1.89:35324,r=calendar.google.com/142.250.68.174:443,OPEN,fill=-,flush=-,to=903634/0}

splatch · April 11, 2022, 3:03pm

This one is HTTP client call. So this is a failed request openHAB icloud binding is trying to do.

BigGeorgeTx · April 11, 2022, 3:10pm

OK. So I think I should increase the log level and when I capture it, open a new thread for an iCloud binding issue. Does that sound like the right approach? (I want to be a good openHAB citizen, but sometimes I’m not sure the best way to do that).

BigGeorgeTx · April 12, 2022, 4:31pm

After a couple of days of not using the openHAB iOS app, and not seeing the “Could not send message.” error, today I tried using the iOS app to send some commands to open and close the garage door using rollershutter items linked to a MyQ binding Thing. To rule out the MyQ binding, I tried another command on the openHAB iOS app (using the MQTT generic binding controlling a Tasmota wall switch). That also produced the error.

I opened a new thread on the iOS app Commands entered in iOS App result in "interceptor.Fault: Could not send Message."