I have discovered a bug with OH 3.2m4 with Map Transformation and a large .items file.
This .items file was taken directly from an OH 2.4 working platform and it works natively fine when Map Transformation is NOT installed on OH 3.2m4. Once I install it, I get errors such as this from the REST API (http://openhabian:8080/rest/items).
{"link":"http://openhabian:8080/rest/items/Dimmer_StringLights_State","state":"1002.0","transformedState":"Short Released Butto"{\"error\":{\"message\":\"begin 0, end -1, length 12\",\"http-code\":500,\"exception\":{\"class\":\"java.lang.StringIndexOutOfBoundsException\",\"message\":\"begin 0, end -1, length 12\",\"localized-message\":\"begin 0, end -1, length 12\"}}}"
I’m using the basic MAP syntax that OH 2.x has used → “State [MAP(HUERemote.map):%s]”
This is just one example, if I reload the REST API it will be a different item next time.
Here’s another thread I discuss the same thing, thinking I resolved it BUT it’s tied to Map Transformation Service.
2021-11-16 17:09:58.236 [ERROR] [rg.apache.cxf.jaxrs.utils.JAXRSUtils] - Problem with writing the data, class org.openhab.core.io.rest.Stream2JSONInputStream, ContentType: application/json
2021-11-16 17:09:58.248 [ERROR] [internal.JSONResponseExceptionMapper] - Unexpected exception occurred while processing REST request.
java.lang.StringIndexOutOfBoundsException: begin 0, end -1, length 12
at java.lang.String.checkBoundsBeginEnd(String.java:3319) ~[?:?]
at java.lang.String.substring(String.java:1874) ~[?:?]
at org.openhab.core.transform.AbstractFileTransformationService.getLocalizedProposedFilename(AbstractFileTransformationService.java:274) ~[?:?]
at org.openhab.core.transform.AbstractFileTransformationService.transform(AbstractFileTransformationService.java:135) ~[?:?]
at org.openhab.core.transform.TransformationHelper.transform(TransformationHelper.java:125) ~[?:?]
at org.openhab.core.transform.TransformationHelper.transform(TransformationHelper.java:100) ~[?:?]
at org.openhab.core.io.rest.core.item.EnrichedItemDTOMapper.considerTransformation(EnrichedItemDTOMapper.java:131) ~[?:?]
at org.openhab.core.io.rest.core.item.EnrichedItemDTOMapper.map(EnrichedItemDTOMapper.java:68) ~[?:?]
at org.openhab.core.io.rest.core.item.EnrichedItemDTOMapper.map(EnrichedItemDTOMapper.java:62) ~[?:?]
at org.openhab.core.io.rest.core.internal.item.ItemResource.lambda$2(ItemResource.java:215) ~[?:?]
at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195) ~[?:?]
at java.util.HashMap$KeySpliterator.tryAdvance(HashMap.java:1642) ~[?:?]
at java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(StreamSpliterators.java:294) ~[?:?]
at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(StreamSpliterators.java:206) ~[?:?]
at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(StreamSpliterators.java:169) ~[?:?]
at java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(StreamSpliterators.java:300) ~[?:?]
at java.util.Spliterators$1Adapter.hasNext(Spliterators.java:681) ~[?:?]
at org.openhab.core.io.rest.Stream2JSONInputStream.fillBuffer(Stream2JSONInputStream.java:94) ~[?:?]
at org.openhab.core.io.rest.Stream2JSONInputStream.read(Stream2JSONInputStream.java:70) ~[?:?]
at java.io.InputStream.read(InputStream.java:280) ~[?:?]
at java.io.InputStream.transferTo(InputStream.java:704) ~[?:?]
at org.openhab.core.io.rest.core.internal.GsonMessageBodyWriter.writeTo(GsonMessageBodyWriter.java:84) ~[?:?]
at org.openhab.core.io.rest.core.internal.MediaTypeExtension.writeTo(MediaTypeExtension.java:84) ~[?:?]
at org.apache.cxf.jaxrs.utils.JAXRSUtils.writeMessageBody(JAXRSUtils.java:1543) ~[bundleFile:3.4.5]
at org.apache.cxf.jaxrs.interceptor.JAXRSOutInterceptor.serializeMessage(JAXRSOutInterceptor.java:249) ~[bundleFile:3.4.5]
at org.apache.cxf.jaxrs.interceptor.JAXRSOutInterceptor.processResponse(JAXRSOutInterceptor.java:122) ~[bundleFile:3.4.5]
at org.apache.cxf.jaxrs.interceptor.JAXRSOutInterceptor.handleMessage(JAXRSOutInterceptor.java:84) ~[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) [?:?]
Considering the code, it could happen in case you missed the extension (.map).
Are you really sure that you use everywhere something like “[MAP(HUERemote.map):%s]” and never [MAP(HUERemote):%s] ?
This is literarily copying the .item and .map files from OH 2.x to OH 3.x.
If I comment out that specific item, it will randomly choose another item that has mapping tied to it. It happens at the end of the REST API call, meaning it works (displays properly) for about 1500+ items then it starts the issue failing.
I believe it could be a memory error on the mapping transition binding OR it could be a timeout issue going across the REST API calling the mapping transition binding.
I wish I could set the timeout value either on the REST API or map transition binding to something higher to rule that out.
But from this and other examples, it would appear that the actual MAP transform has already taken place but the output text gets cut off and error JSON inserted. "transformedState":"Short Released Butto"{\"error\":{\"message\"
i.e. not a fundamental transform problem, but something like a timeout or messed-up return format.
In the linked thread the unexpected error gets inserted at different points in REST output, not always in transformedState, e.g. in the middle of options
No thanks, I’ve zero insight into how REST API builds its output either.
I speculate it’s something else messing up - retrieving Item options or whatever - because of extra time taken by transformation. Based on working OK with MAP disabled. Trying a transformation with more overhead like JS might show it up more.
What’s the host box here? Sometimes race conditions show upon higher powered multi-core boxes beyond the average plodding Pi.
This part seems consistent - {\"error\":{\"message\":\"begin 0, end -1, length 12\" ...
but I wouldn’t know if “always 12” is a clue. Looks like we’re trying to get char 12 from an empty string somewhere.
Doesn’t seem extra special. Guessing you’re using openhabian and so have zram active, which should I think put the JSONDB in memory for speed. Ordinary enough.
Looking like sheer number of Items is the unique factor ??
Might be relevant. Building JSON for all Items hammers the JSONDB - I don’t know if all/some is held in memory (hurrah for freeing up with ZRAM off !) and/or in filestore (boo for no ZRAM to speed up i/o access !).
The API will hit multiple JSONDB to assemble each Item, and obviously transforms on top is further file accesses.
Likely irrelevant. xxx.items file is parsed once at bootup and converted to a working copy in JSONDB.
