After upgrade 2.2.0-1 (Stable) to 2.3.0-1 (Stable) & iOS (11.4.1) App: ServerRuntime$Responder - I/O error when closing the app

Hi All,

I upgraded from OpenHABian 2.2.0-1 (Stable) to 2.3.0-1 (Stable) today (RasPI 3) and used the chance to transfer the 2.2.0 installation before on a brand new SD card.
Still it was quite a challenge as it took me like 4 times with restoring backup images repeatedly as every time some other issue (logs full of various errors, no openhab logs anymore, problems with the ‘openhab-binding-weather1’ binding) occured and efforts to fix (like eg. deleting the cache and temp) always messed up even more… so back to start again and again.

But while by now things finally don’t look so bad there is one thing that worries me:

Every time I close (=terminate) the iOS App (running iOS 11.4.1) the following error is logged in openhab.log.
I tried from different devices and the behaviour can clearly be reproduced (it doesn’t matter if I did connect locally or through myopenhab.org / the cloud connector ).

2018-07-15 19:54:34.240 [ERROR] [ersey.server.ServerRuntime$Responder] - An I/O error has occurred while writing a response message entity to the container output stream.
org.glassfish.jersey.server.internal.process.MappableException: org.eclipse.jetty.io.EofException
at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:92) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.message.internal.MessageBodyFactory.writeTo(MessageBodyFactory.java:1130) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:711) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:444) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:434) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:329) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [15:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:584) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.3.21.v20170918]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:284) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.Server.handle(Server.java:534) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108) [76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: org.eclipse.jetty.io.EofException
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:199) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:420) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:313) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:147) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:731) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224) ~[87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:519) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:745) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:801) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:235) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:219) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:496) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at java.io.OutputStream.write(OutputStream.java:75) ~[?:?]
at org.glassfish.jersey.servlet.internal.ResponseWriter$NonCloseableOutputStreamWrapper.write(ResponseWriter.java:320) ~[?:?]
at org.glassfish.jersey.message.internal.CommittingOutputStream.write(CommittingOutputStream.java:218) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$UnCloseableOutputStream.write(WriterInterceptorExecutor.java:294) ~[?:?]
at org.eclipse.smarthome.io.rest.core.internal.GsonProvider.writeTo(GsonProvider.java:71) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.invokeWriteTo(WriterInterceptorExecutor.java:265) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.aroundWriteTo(WriterInterceptorExecutor.java:250) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?]
at org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor.aroundWriteTo(JsonWithPaddingInterceptor.java:106) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?]
at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:86) ~[?:?]
… 46 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:148) ~[?:?]
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:?]
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:179) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:420) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:313) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:147) ~[76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:731) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224) ~[87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:519) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:745) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:801) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:235) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:219) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:496) ~[84:org.eclipse.jetty.server:9.3.21.v20170918]
at java.io.OutputStream.write(OutputStream.java:75) ~[?:?]
at org.glassfish.jersey.servlet.internal.ResponseWriter$NonCloseableOutputStreamWrapper.write(ResponseWriter.java:320) ~[?:?]
at org.glassfish.jersey.message.internal.CommittingOutputStream.write(CommittingOutputStream.java:218) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$UnCloseableOutputStream.write(WriterInterceptorExecutor.java:294) ~[?:?]
at org.eclipse.smarthome.io.rest.core.internal.GsonProvider.writeTo(GsonProvider.java:71) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.invokeWriteTo(WriterInterceptorExecutor.java:265) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.aroundWriteTo(WriterInterceptorExecutor.java:250) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?]
at org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor.aroundWriteTo(JsonWithPaddingInterceptor.java:106) ~[?:?]
at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?]
at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:86) ~[?:?]
… 46 more

Would anybody have any good idea about this behaviour and how to fix this?
As said my experience with generally deleting the Cache and the Temp folders content was more than frightening - so I would really like to avoid to do this.

Is there maybe a more specific approach (one that a simple user could perform) or would it make sense to remove and reinstall the openHAB Cloud Connector (which would surprise me though…)…

Thanks to everybody taking the effort to help or contribute with own experiences in this regards!

Chris

Follow up:

As I had some time I did dig a bit more into this:

1.) I by chance noticed that the respective error shows up if the OpenHAB App is closed “too early”. So after a certain point in time this doesn’t occur. I though can’t tell how long the App needs to be opened (can be in the background as well.

2.) I created a clone of SD card to play around with and gave the “Delete cache and temp” approach a try.
==> Outcome: this didn’t change anything at all

3.) I did restore the systems state as of 01. April 2018 / Version 2.2.0-1 Stable and give it a try with this
==> Outcome: The error shows up equally

4.) As of the finding above I took previous logs I had stored and found out that the error indeed shows up since quite a while - I could find it for the first time logged at May 11, 2018.

Based on this I have to apologize, the issue is NOT related to the upgrade to V2.3.0-1 Stable - but seems to exist longer.
Probably the thread is therefore in the wrong container - maybe some admin can move it to the right one?

Secondly I am wondering if this is more an App related issue - like channels not being closed properly if the app is terminated too early? Just an idea of a noobie though…

Any Idea how I should / could proceed in this regards?

Thanks a lot!