search

eclipse-archived / smarthome

Eclipse SmartHome™ project
https://www.eclipse.org/smarthome/
Eclipse Public License 2.0
861 stars 784 forks source link

Get list of item via REST API returns null reference exception (error 500) #3676

Closed pgfeller closed 7 years ago

pgfeller commented 7 years ago

Hi,

using OH 2 build 947 I have the following issue (discussed in https://community.openhab.org/t/rest-items-does-not-work-faulty-item-definition/30052):

A rest query for all items returns: "error": { "http-code": 500, "exception": { "class": "java.lang.NullPointerException" } } }

Karaf is able to list the items (smarthome:items list) - classic UI and rules work well, but paper ui and others that use the REST API do report this error. From the .log files I'm not able to see which items causes that problem: 2017-06-16 00:28:22.668 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@7895d3{r=3,c=false,a=IDLE,uri=/rest/items} messageComplete 2017-06-16 00:28:22.669 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1fa42a3 EOF 2017-06-16 00:28:22.669 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@7895d3{r=3,c=false,a=IDLE,uri=/rest/items} handle enter 2017-06-16 00:28:22.669 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@165e98a{s=IDLE i=true a=null} handling IDLE 2017-06-16 00:28:22.670 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@7895d3{r=3,c=false,a=DISPATCHED,uri=/rest/items} action REQUEST_DISPATCH 2017-06-16 00:28:22.670 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST GET /rest/items on HttpChannelOverHttp@7895d3{r=3,c=false,a=DISPATCHED,uri=/rest/items} 2017-06-16 00:28:22.671 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/items]... 2017-06-16 00:28:22.671 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/items] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-16,name=org.ops4j.pax.web.service.spi.model.ServletModel-16,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@1d4a273,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-15,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [10], contextID=default],contextParams={},virtualHosts={},connectors={}}}} 2017-06-16 00:28:22.671 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [10], contextID=default]} 2017-06-16 00:28:22.672 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [10], contextID=default]} 2017-06-16 00:28:22.672 [DEBUG] [org.eclipse.jetty.server.session ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@315a86 2017-06-16 00:28:22.672 [DEBUG] [org.eclipse.jetty.server.session ] - session=null 2017-06-16 00:28:22.672 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/items -> org.ops4j.pax.web.service.spi.model.ServletModel-16@b9f03e5d==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true 2017-06-16 00:28:22.673 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/items] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [10], contextID=default]] 2017-06-16 00:28:22.673 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@a0a33b, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@189ea30 2017-06-16 00:28:22.673 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null 2017-06-16 00:28:22.715 [DEBUG] [ersey.server.ServerRuntime$Responder] - Starting mapping of the exception. org.glassfish.jersey.server.internal.process.MappableException: java.lang.NullPointerException at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.mapTargetToRuntimeEx(AbstractJavaResourceMethodDispatcher.java:179)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.access$200(AbstractJavaResourceMethodDispatcher.java:72)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:149)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors.process(Errors.java:315)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors.process(Errors.java:297)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors.process(Errors.java:267)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[10:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.19.v20160908] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.19.v20160908] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.19.v20160908] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:287)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.19.v20160908] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[72:org.eclipse.jetty.io:9.2.19.v20160908] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.19.v20160908] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.19.v20160908] at java.lang.Thread.run(Thread.java:745)[:1.8.0_101] Caused by: java.lang.NullPointerException at org.eclipse.smarthome.io.rest.core.item.EnrichedItemDTOMapper.considerTransformation(EnrichedItemDTOMapper.java:96) at org.eclipse.smarthome.io.rest.core.item.EnrichedItemDTOMapper.map(EnrichedItemDTOMapper.java:47) at org.eclipse.smarthome.io.rest.core.item.EnrichedItemDTOMapper.map(EnrichedItemDTOMapper.java:41) at org.eclipse.smarthome.io.rest.core.item.ItemResource.getItemBeans(ItemResource.java:569) at org.eclipse.smarthome.io.rest.core.item.ItemResource.getItems(ItemResource.java:152) at sun.reflect.GeneratedMethodAccessor867.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_101] at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_101] at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)[159:org.glassfish.jersey.core.jersey-server:2.22.2] ... 42 more 2017-06-16 00:28:22.739 [DEBUG] [ersey.server.ServerRuntime$Responder] - Exception 'null' has been mapped by 'org.eclipse.smarthome.io.rest.JSONResponse$ExceptionMapper' to response 'Internal Server Error' (500:SERVER_ERROR). 2017-06-16 00:28:22.740 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@15a4304[PROCESSING][i=ResponseInfo{HTTP/1.1 500 Internal Server Error,115,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@a4d0c9] generate: NEED_HEADER (null,[p=0,l=115,c=8192,r=115],true)@START 2017-06-16 00:28:22.741 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@15a4304[PROCESSING][i=ResponseInfo{HTTP/1.1 500 Internal Server Error,115,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@a4d0c9] generate: FLUSH ([p=0,l=161,c=8192,r=161],[p=0,l=115,c=8192,r=115],true)@COMPLETING 2017-06-16 00:28:22.742 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 276 SelectChannelEndPoint@14f21ee{/192.168.0.10:53265<->8080,Open,in,out,-,W,81/30000,HttpConnection}{io=0,kio=0,kro=1} 2017-06-16 00:28:22.742 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@15a4304[PROCESSING][i=ResponseInfo{HTTP/1.1 500 Internal Server Error,115,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@a4d0c9] generate: DONE ([p=161,l=161,c=8192,r=0],[p=115,l=115,c=8192,r=0],true)@END 2017-06-16 00:28:22.743 [TRACE] [jersey.process.internal.RequestScope] - [DEBUG] Released scope instance Instance{id=d54d7d45-5a5e-48c7-9bdd-f7cbfc8dc331, referenceCounter=0, store size=0} on thread qtp14434062-19342 - /rest/items 2017-06-16 00:28:22.744 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ o.e.j.s.h.ContextHandler@135bef5{/static,null,AVAILABLE} 2017-06-16 00:28:22.744 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0.201706122104 [167], contextID=default]} 2017-06-16 00:28:22.744 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201706091022 [100], contextID=default]} 2017-06-16 00:28:22.745 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0.201706122104 [171], contextID=default]} 2017-06-16 00:28:22.745 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@11754fe} 2017-06-16 00:28:22.745 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201706091022 [137], contextID=default]} 2017-06-16 00:28:22.745 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201706091022 [138], contextID=default]} 2017-06-16 00:28:22.746 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.1.0.201706122104 [215], contextID=default]} 2017-06-16 00:28:22.746 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201706091022 [196], contextID=default]} 2017-06-16 00:28:22.746 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=org.openhab.io.net.http.SecureHttpContext@9a5381} 2017-06-16 00:28:22.746 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=org.openhab.io.net.http.SecureHttpContext@3d2498} 2017-06-16 00:28:22.746 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201706091022 [197], contextID=default]} 2017-06-16 00:28:22.747 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0.201706122104 [223], contextID=default]} 2017-06-16 00:28:22.747 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/items @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habmin_2.1.0.201706122104 [229], contextID=default]} 2017-06-16 00:28:22.747 [DEBUG] [org.eclipse.jetty.server.Server ] - RESPONSE /rest/items 500 handled=true 2017-06-16 00:28:22.747 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@165e98a{s=DISPATCHED i=true a=null} unhandle DISPATCHED 2017-06-16 00:28:22.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - reset HttpParser{s=END,0 of -1} 2017-06-16 00:28:22.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - END --> START 2017-06-16 00:28:22.748 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@7895d3{r=3,c=false,a=IDLE,uri=} handle exit, result COMPLETE 2017-06-16 00:28:22.749 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@14f21ee{/192.168.0.10:53265<->8080,Open,in,out,-,-,6/30000,HttpConnection}{io=0,kio=0,kro=1} 2017-06-16 00:28:22.749 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@14f21ee{/192.168.0.10:53265<->8080,Open,in,out,-,-,7/30000,HttpConnection}{io=0,kio=0,kro=1} 2017-06-16 00:28:22.749 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@474b7f[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 200 OK\r\n...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}

It would be nice if the error message states which item is affected. We discussed this in the forum and assume that this is an issue with OH2 itself.

Please let me know if additional information is required.

with kind regards, Patrik

kaikreuzer commented 7 years ago

Thanks for reporting, this is clearly a bug in EnrichedItemDTOMapper.

pgfeller commented 7 years ago

Many thanks for the feedback. After some experiments I've found that the problem is gone after I cleaned the tmp directory. I wonder if I did make a mistake during the update ... Maybe it would be worth to clean the tmp @ startup - or after an upgrade automatically?

Not sure if this is to be handled as bug, or user error - maybe no action is required; but as many problems in the forum are solved by cleaning the tmp it might be worth to consider such an autoclean for all platforms (I'm on M$-Windows 10 x86).

with kind regards, Patrik

kaikreuzer commented 7 years ago

Maybe it would be worth to clean the tmp @ startup - or after an upgrade automatically?

Both cache and tmp folders are cleaned on an apt upgrade. The cache cleaning has been missing until yesterday, but is in place now as well: https://github.com/openhab/openhab-linuxpkg/pull/51.

As you cannot reproduce it anymore, I close this issue. Nonetheless, I think that an NPE should not happen at that place, but I cannot really say what was null and if that only occurred because of a messed up installation...