All Things are gone after restarting openHAB

Michdo93 · March 24, 2023, 2:51pm

I found out that the data was lost because the server crashed. So the json files were not written completely accordingly.

I have restored the org.openhab.core.thing.Thing.json. I have compared with a backup file what was still missing in the corrupt file. This works a bit better than the old backup, which was still designed for openHAB 2.

However, I still have a problem even though I stopped openHAB, cleared the cache and started it again.

The first problem is:

15:32:01.890 [ERROR] [org.apache.cxf.jaxrs.utils.JAXRSUtils] - Problem with writing the data, class org.openhab.core.io.rest.Stream2JSONInputStream, ContentType: application/json
15:32:01.900 [ERROR] [.internal.JSONResponseExceptionMapper] - Unexpected exception occurred while processing REST request.
java.lang.IllegalArgumentException: Last segment must not be blank: [zwave, device, a61d9ee8, node2, ]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:79) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:59) ~[?:?]
        at org.openhab.core.thing.UID.<init>(UID.java:57) ~[?:?]
        at org.openhab.core.thing.ThingUID.<init>(ThingUID.java:139) ~[?:?]
        at org.openhab.core.thing.ChannelUID.getThingUID(ChannelUID.java:150) ~[?:?]
        at org.openhab.core.thing.internal.ThingRegistryImpl.getChannel(ThingRegistryImpl.java:80) ~[?:?]
        at org.openhab.core.thing.internal.ChannelStateDescriptionProvider.getStateDescription(ChannelStateDescriptionProvider.java:97) ~[?:?]
        at org.openhab.core.thing.internal.ChannelStateDescriptionProvider.getStateDescriptionFragment(ChannelStateDescriptionProvider.java:86) ~[?:?]
        at org.openhab.core.internal.service.StateDescriptionServiceImpl.getMergedStateDescriptionFragments(StateDescriptionServiceImpl.java:71) ~[?:?]
        at org.openhab.core.internal.service.StateDescriptionServiceImpl.getStateDescription(StateDescriptionServiceImpl.java:63) ~[?:?]
        at org.openhab.core.items.GenericItem.getStateDescription(GenericItem.java:409) ~[?:?]
        at org.openhab.core.io.rest.core.item.EnrichedItemDTOMapper.considerTransformation(EnrichedItemDTOMapper.java:143) ~[?:?]
        at org.openhab.core.io.rest.core.item.EnrichedItemDTOMapper.map(EnrichedItemDTOMapper.java:81) ~[?:?]
        at org.openhab.core.io.rest.core.item.EnrichedItemDTOMapper.map(EnrichedItemDTOMapper.java:64) ~[?:?]
        at org.openhab.core.io.rest.core.internal.item.ItemResource.lambda$2(ItemResource.java:222) ~[?:?]
        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:91) ~[?:?]
        at org.openhab.core.io.rest.Stream2JSONInputStream.read(Stream2JSONInputStream.java:67) ~[?:?]
        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:83) ~[?:?]
        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.46.v20220331]
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[bundleFile:9.4.46.v20220331]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:74) ~[bundleFile:?]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[bundleFile:9.4.46.v20220331]
        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.46.v20220331]
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.46.v20220331]
        at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:90) ~[bundleFile:?]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.46.v20220331]
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.46.v20220331]
        at java.lang.Thread.run(Thread.java:829) [?:?]

And then I have multiple times problems with the error Cannot inform the listener "org.openhab.core.thing.internal.ChannelLinkNotifier@XXXXX" about the "ADDED" event: Last segment must not be blank: [zwave, device, YYYYY, node2, ] java.lang.IllegalArgumentException: Last segment must not be blank.

The Z-Wave devices were also the ones listed last in the org.openhab.core.thing.Thing.json file.

The org.openhab.core.items.Item.json file is empty.

Which makes me wonder. Is it not possible to simply re-read everything? I don’t know now where there is another mistake. All bindings are installed. Things are also all present. Ultimately, this means that there is an error in the channels between Things and Items or in the Items.

The REST API still says: SyntaxError: JSON.parse: expects ',' or '}' after the property value in the object in row 1 column 1375599 of the JSON data.

mstormi · March 24, 2023, 4:22pm

Nah. A file is never corrupted because of ZRAM. Don’t put up rumours, please.
It can be empty if you ran out of (ZRAM) space when writing or it can be outdated because it was recovered on (re)boot so you’re ‘set back’ in time to when it was written back to disk/SD last time.
But it’ll be just as corrupted as it was when it was saved for the last time (read: not).
And by the way the jsondb directory isn’t on ZRAM.
And by the way that’ll be on openHABian on Raspi only. But OP said he’s using Ubuntu.

wborn · March 24, 2023, 8:21pm

I missed that but Ubuntu is a nice OS and I also like using it especially on very new hardware!

gforums · June 3, 2023, 10:54am

I today have the same behaviour as written here. I am on latest OH 3.4.4 Release build, I had a power cut and now all org.openhab.core.thing.Thing files in the jsondb folder and the backup folder underneath are empty with 0kb.

Lost all my items now.
How can that happen? I’ll check whether I can find a backup to use…

Device is a raspberry Pi.

thanks,
Christian

David_Salas · July 17, 2023, 1:38am

it happened to me to i’m using OH 3.4.4 too, any ideas how to fix?

Sundeep_Goel · October 20, 2023, 7:52am

I have the same problem. For me, all things defined in a things file disappear after oh or system restart, and reapper if the file is touched or saved again when oh is running.

Tried all above suggested fixes, nothing works.
Log files give no indication of any issue.

I even upgraded to 4.10 from 4.0.3 to check it that solved the issue. It didn’t.

Any pointers to further debug the issue?

Sundeep_Goel · October 20, 2023, 12:56pm

Found something in the logs

2023-10-20 18:11:05.025 [DEBUG] [org.openhab.core.model.core.internal.folder.FolderObserver                      ] - Adding files in '/etc/openhab/things' to the model
2023-10-20 18:11:05.029 [DEBUG] [org.openhab.core.model.core.internal.folder.FolderObserver                      ] - Missing parser for 'things' extension, added ignored path: /etc/openhab/things/mqtt.things
2023-10-20 18:11:05.034 [DEBUG] [org.openhab.core.model.core.internal.folder.FolderObserver                      ] - Missing parser for 'things' extension, added ignored path: /etc/openhab/things/gpstrackers.things
2023-10-20 18:11:05.037 [DEBUG] [org.openhab.core.model.core.internal.folder.FolderObserver                      ] - Missing parser for 'things' extension, added ignored path: /etc/openhab/things/things.things
2023-10-20 18:11:05.043 [DEBUG] [org.openhab.core.model.core.internal.folder.FolderObserver                      ] - Missing parser for 'things' extension, added ignored path: /etc/openhab/things/telegram.things

Above entries are way above the entry for parser invocation.

2023-10-20 18:11:09.012 [DEBUG] [org.openhab.core.model.core.internal.folder.FolderObserver                      ] - Adding parser for 'things' extension

So whats seems to be happening is that the by the time the parser is initialised various files have been added to the “ignored path”.

How does one fix the issue - seems parsers need to get loaded ahead in the startup sequence ?

wborn · October 20, 2023, 1:23pm

It’s normal and it should process the ignored paths once the parser is added.

When the parser is added and it completes processing the ignored things paths it should log:

Finished processing ignored paths for ‘things’ extension. X ignored paths remain

Sundeep_Goel · October 20, 2023, 1:30pm

Thanks, I get log entries for rules and scripts, but not for things. That probably explains why the others load but not things.

Final entry is

Finished processing ignored paths for ‘rules’ extension. 7 ignored paths remain

How to debug further ?

wborn · October 20, 2023, 1:35pm

The easiest is if you post the complete logging so we can have a look.

Sundeep_Goel · October 20, 2023, 1:37pm

done

I have enabled trace only on some components, please let me know if you need levels increased for others.

Logger                                                          │ Level
────────────────────────────────────────────────────────────────┼──────
*                                                               │ WARN
ROOT                                                            │ WARN
e.internal.SseItemStatesEventBuilder                            │ WARN
javax.jmdns                                                     │ WARN
javax.mail                                                      │ WARN
openhab.event                                                   │ WARN
openhab.event.AddonEvent                                        │ WARN
openhab.event.ChannelDescriptionChangedEvent                    │ WARN
openhab.event.InboxUpdatedEvent                                 │ WARN
openhab.event.ItemAddedEvent                                    │ WARN
openhab.event.ItemChannelLinkAddedEvent                         │ WARN
openhab.event.ItemChannelLinkRemovedEvent                       │ WARN
openhab.event.ItemRemovedEvent                                  │ WARN
openhab.event.ItemStateEvent                                    │ WARN
openhab.event.RuleAddedEvent                                    │ WARN
openhab.event.RuleRemovedEvent                                  │ WARN
openhab.event.RuleStatusInfoEvent                               │ WARN
openhab.event.StartlevelEvent                                   │ INFO
openhab.event.ThingAddedEvent                                   │ INFO
openhab.event.ThingRemovedEvent                                 │ INFO
openhab.event.ThingStatusInfoEvent                              │ INFO
openhab.event.ThingUpdatedEvent                                 │ INFO
org.apache.cxf.jaxrs.sse.SseEventSinkImpl                       │ WARN
org.apache.karaf.jaas.modules.audit                             │ WARN
org.apache.karaf.kar.internal.KarServiceImpl                    │ WARN
org.apache.karaf.shell.ssh.SshUtils                             │ WARN
org.apache.karaf.shell.support                                  │ WARN
org.apache.sshd                                                 │ WARN
org.eclipse.lsp4j                                               │ WARN
org.jupnp                                                       │ WARN
org.openhab                                                     │ INFO
org.openhab.binding.generic                                     │ WARN
org.openhab.binding.homeassistant                               │ WARN
org.openhab.binding.mqtt                                        │ INFO
org.openhab.binding.mqtt.generic                                │ TRACE
org.openhab.binding.mqtt.homeassistant                          │ WARN
org.openhab.core.io.rest.sse.internal.SseItemStatesEventBuilder │ WARN
org.openhab.core.model.core.internal.ModelRepositoryImp         │ TRACE
org.openhab.core.model.core.internal.folder.FolderObserver      │ TRACE
org.ops4j.pax.url.mvn.internal.AetherBasedResolver              │ WARN
org.ops4j.pax.web.pax-web-runtime                               │ WARN
penhab.event.ItemStateEvent                                     │ WARN

openhab.log (137.4 KB)

wborn · October 20, 2023, 1:45pm

Thanks for the logging. It seems to confirm one hypothesis I had for why the issue might occur. I think what happens is that parsers are added by other threads during activation. In that case it doesn’t process the ignored paths so I’ll create a fix for that scenario. During my own testing this never happened… probably because I’ve tested using faster hardware.

Sundeep_Goel · October 20, 2023, 1:49pm

Thanks , i suspected that might been an issue since am running on really old hw rpi2

Q: why do the other parsers get added and parse the backlog, but not things ?

Is there any “hack” I can deploy in the interim to mitigate the issue ?

wborn · October 20, 2023, 1:52pm

It’s because those parsers are added after the component has been activated, i.e. after this log statement:

FolderObserver has been activated

After it happens you can move the files temporarily to another folder and then move them back. That should retrigger the logic for adding the files.

tiknx · October 20, 2023, 2:16pm

I added the system info binding and the execute binding via gui. Then I added a rule, that moves all file from /etc/openhab/things to /tmp and move it back when system is up for 5minutes

I also use a raspberry pi. But a raspberry pi 4. So this ist still not a very fast hardware, but ways faster than rpi2

Sundeep_Goel · October 20, 2023, 3:12pm

i get that, my query is that once the parsers are activated they clear “ignored paths” except for things. Why would things related paths remain unprocessed when others seem to work fine in the same scenario.

In above ignored paths was 32 before parsers got loaded. thereafter rules and scripts parsing ran leaving behind 7 for things.

Processing 32 ignored paths for 'script' extension
Processing 32 ignored paths for 'rules' extension
Finished processing ignored paths for 'rules' extension. 7 ignored paths remain

wborn · October 20, 2023, 3:23pm

It’s because in the other cases the parser was added before it starts processing files during activation.

Sundeep_Goel · October 20, 2023, 3:32pm

Thanks. btw, when will the fix go in (appreciate there would be other with higher priority on the backlog) and how would I be able to apply it on my setup ?

Do you want me to open bug / issue ticket for tracking ?

wborn · October 20, 2023, 4:34pm

We already have a few issues for this.

I just created a PR with a fix:

Now I need to test it.

wborn · October 20, 2023, 7:27pm

It still works fine for me but I still cannot reproduce that parsers are added by other threads.

To test the fix, update the bundle on the Karaf console using one of these commands and then restart openHAB.

OH 4.0.x

bundle:update org.openhab.core.model.core https://github.com/wborn/openhab-core/releases/download/folder-observer-20231020/org.openhab.core.model.core-4.0.4-SNAPSHOT.jar

Recent OH 4.1.0-SNAPSHOTs or OH 4.1.0.M2

bundle:update org.openhab.core.model.core https://github.com/wborn/openhab-core/releases/download/folder-observer-20231020/org.openhab.core.model.core-4.1.0-SNAPSHOT.jar