Update from OH4.0.1 to 4.0.2 (docker) results in ERROR:HANDLER for 99% of openhab things

Scriptwriter · August 16, 2023, 8:51am

Hi all,

i did on my docker install an update from 4.0.1 which was running mostly fine to 4.0.2.
But i got into trouble that 99% of my things are no more online: “Error:Handler” (all KNX, IP Camera, URL…) Only Solarforecast Thing is Online

So it cannot get states from things/items, nothing works any more. So i tried make some restarts and also to use 4.0.1 again but i guess something on volumes was converted.

In log i cannot see a hint how to fix:

2023-08-16 10:15:24.341 [INFO ] [org.openhab.core.Activator          ] - Starting openHAB 4.0.2 (build Release Build)
2023-08-16 10:15:26.751 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://openhab/rest/events's Observer 
2023-08-16 10:15:26.752 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://redacted:7070/rest/items/scanmanual/state's Observer 
2023-08-16 10:15:26.789 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Zurich'.
2023-08-16 10:15:26.816 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '46.976803555497355,9.577779290347854'.
2023-08-16 10:15:26.820 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_CH'.
2023-08-16 10:15:26.823 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SI'.
2023-08-16 10:15:37.546 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://openhab/rest/events's Observer 
2023-08-16 10:16:42.220 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'haus_user.items'
2023-08-16 10:16:43.526 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2023-08-16 10:16:44.552 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'haus_user.sitemap'
2023-08-16 10:16:44.948 [INFO ] [el.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'haus_user.sitemap', using it anyway:
Frames must not contain other frames
2023-08-16 10:16:45.361 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'dsmr.things'
2023-08-16 10:16:45.464 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'telegram.things'
2023-08-16 10:16:45.493 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.things'
2023-08-16 10:16:52.608 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://redacted:7070/rest/metrics/prometheus's Observer 
2023-08-16 10:16:57.369 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.script'
2023-08-16 10:16:59.493 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2023-08-16 10:17:00.118 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'error.rules'
2023-08-16 10:17:03.866 [WARN ] [.transport.servlet.ServletController] - Can't find the request for http://redacted:7070/rest/items/scanmanual/state's Observer 
2023-08-16 10:17:09.523 [INFO ] [abspeaker.internal.ui.HABSpeakerTile] - Started HABSpeaker at /habspeaker
2023-08-16 10:17:09.585 [INFO ] [internal.SolarForecastHandlerFactory] - Persistence null cannot be queried. Feature Solcast Tuninng will not work
2023-08-16 10:17:10.601 [WARN ] [oice.voskstt.internal.VoskSTTService] - IOException loading model: missing model dir: /openhab/userdata/vosk/model
2023-08-16 10:17:12.924 [ERROR] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngine for language 'application/javascript;version=ECMAScript-5.1' could not be found for identifier: f0999683-3a8b-44b7-9fa9-208c148c3c4e
2023-08-16 10:17:12.930 [ERROR] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngine for language 'application/javascript;version=ECMAScript-5.1' could not be found for identifier: 8f664335-ed20-4ce0-919b-fdad822f85cb
2023-08-16 10:17:12.932 [ERROR] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngine for language 'application/javascript' could not be found for identifier: bd375334-18c0-49bd-be9a-d51a1c35cc90
2023-08-16 10:17:12.935 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.

Is it possible to get the system running again or do i have to restore the volumes from backups?

Bundle:List:

openhab> bundle:list
START LEVEL 100 , List Threshold: 50
 ID │ State  │ Lvl │ Version                │ Name
────┼────────┼─────┼────────────────────────┼───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
 30 │ Active │  80 │ 2.14.1                 │ Jackson-annotations
 31 │ Active │  80 │ 2.14.1                 │ Jackson-core
 32 │ Active │  80 │ 2.14.1                 │ jackson-databind
 33 │ Active │  80 │ 2.14.1                 │ Jackson-dataformat-YAML
 34 │ Active │  80 │ 2.14.1                 │ Jackson datatype: JSR310
 35 │ Active │  80 │ 6.2.6                  │ Woodstox
 36 │ Active │  80 │ 2.9.1                  │ Gson
 37 │ Active │  80 │ 30.1.0.jre             │ Guava: Google Core Libraries for Java
 38 │ Active │  80 │ 1.0.1                  │ Guava InternalFutureFailureAccess and InternalFutures
 39 │ Active │  80 │ 5.0.1.v20210324-2015   │ Google Guice - Core Library
 40 │ Active │  80 │ 5.12.1                 │ jna
 41 │ Active │  80 │ 5.12.1                 │ jna-platform
 43 │ Active │  80 │ 4.8.149.v20220915-0556 │ ClassGraph
 44 │ Active │  80 │ 0.17.1                 │ Directory-Watcher
 45 │ Active │  80 │ 2.1.9                  │ swagger-annotations
 46 │ Active │  80 │ 2.1.9                  │ swagger-core
 47 │ Active │  80 │ 2.1.9                  │ swagger-integration
 48 │ Active │  80 │ 2.1.9                  │ swagger-jaxrs2
 49 │ Active │  80 │ 2.1.9                  │ swagger-models
 51 │ Active │  80 │ 2.0.2                  │ Jakarta Bean Validation API
 53 │ Active │  80 │ 2.3.3                  │ Jakarta XML Web Services API
 54 │ Active │  80 │ 1.2                    │ javax.annotation API
 55 │ Active │  80 │ 3.5.8                  │ JmDNS
 56 │ Active │  80 │ 2.1.3                  │ Units of Measurement API
 58 │ Active │  80 │ 0.5.10                 │ Jollyday
 59 │ Active │  80 │ 3.2.0.v201101311130    │ ANTLR Runtime
 60 │ Active │  80 │ 1.0.0.v201105210816    │ Aopalliance Plug-in
 61 │ Active │  80 │ 1.2.2                  │ org.apache.aries.component-dsl.component-dsl
 62 │ Active │  80 │ 1.0.1                  │ Apache Aries JAX-RS Specification API
 63 │ Active │  80 │ 2.0.0                  │ Apache Aries JAX-RS Whiteboard
 64 │ Active │  80 │ 1.3.6                  │ Apache Aries SPI Fly Dynamic Weaving Bundle
 65 │ Active │  80 │ 3.12.0                 │ Apache Commons Lang
 66 │ Active │  80 │ 3.4.5                  │ Apache CXF Core
 67 │ Active │  80 │ 3.4.5                  │ Apache CXF Runtime JAX-RS Frontend
 68 │ Active │  80 │ 3.4.5                  │ Apache CXF JAX-RS Client
 69 │ Active │  80 │ 3.4.5                  │ Apache CXF JAX-RS Server-Side Events Support
 70 │ Active │  80 │ 3.4.5                  │ Apache CXF Runtime Security functionality
 71 │ Active │  80 │ 3.4.5                  │ Apache CXF Runtime HTTP Transport
 77 │ Active │  80 │ 4.4.3                  │ Apache Karaf :: OSGi Services :: Event
 88 │ Active │  80 │ 1.0.0.2                │ Apache ServiceMix :: Bundles :: javax.inject
 95 │ Active │  80 │ 2.2.5                  │ XmlSchema Core
 96 │ Active │  80 │ 0.9.3                  │ jose4j
 97 │ Active │  80 │ 2.17.0.v20190920-0401  │ EMF Common
 98 │ Active │  80 │ 2.20.0.v20190920-0401  │ EMF Ecore
 99 │ Active │  80 │ 2.14.0.v20190528-0725  │ EMF Change Model
100 │ Active │  80 │ 2.16.0.v20190528-0725  │ EMF XML/XMI Persistence
101 │ Active │  80 │ 3.13.0.v20200828-1034  │ Common Eclipse Runtime
103 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: ALPN :: Client
104 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: ALPN :: JDK9 Client Implementation
110 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: HTTP2 :: Client
117 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: Proxy
125 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: Websocket :: API
126 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: Websocket :: Client
127 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: Websocket :: Common
128 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: Websocket :: Server
129 │ Active │  80 │ 9.4.50.v20221201       │ Jetty :: Websocket :: Servlet Interface
131 │ Active │  80 │ 0.19.0.v20221118-0359  │ org.eclipse.lsp4j
132 │ Active │  80 │ 0.19.0.v20221118-0359  │ org.eclipse.lsp4j.jsonrpc
133 │ Active │  80 │ 2.29.0.v20221121-0915  │ Xtend Runtime Library
134 │ Active │  80 │ 2.29.0.v20221121-0915  │ Xtend Macro Interfaces
135 │ Active │  80 │ 2.29.0.v20221121-0917  │ Xtext
136 │ Active │  80 │ 2.29.0.v20221121-0924  │ Xtext Common Types
137 │ Active │  80 │ 2.29.0.v20221121-0917  │ Xtext IDE Core
138 │ Active │  80 │ 2.29.0.v20221121-0917  │ Xtext Utility
139 │ Active │  80 │ 2.29.0.v20221121-0924  │ Xbase Model
140 │ Active │  80 │ 2.29.0.v20221121-0924  │ Xbase Generic IDE Services
141 │ Active │  80 │ 2.29.0.v20221121-0915  │ Xbase Runtime Library
145 │ Active │  80 │ 9.4.0                  │ org.objectweb.asm.commons
146 │ Active │  80 │ 9.4.0                  │ org.objectweb.asm.tree
147 │ Active │  80 │ 9.4.0                  │ org.objectweb.asm.tree.analysis
148 │ Active │  80 │ 9.4.0                  │ org.objectweb.asm.util
149 │ Active │  80 │ 1.0.0                  │ Fixes for the java.base module
150 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Core
151 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Add-on XML
152 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Marketplace Add-on Services
153 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Community Marketplace Add-on Service :: Karaf
154 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Audio
155 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: JAAS Authentication
156 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: OAuth2Client
157 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Automation
158 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Automation Media Modules
159 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Automation Script Modules
160 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Automation Script RuleSupport
161 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Automation REST API
162 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Configuration Core
163 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Configuration Discovery
164 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Configuration mDNS Discovery
165 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Configuration Dispatcher
166 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Ephemeris
167 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: ID
168 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Console
169 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Console for OSGi runtime Karaf
170 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: HTTP Interface
171 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: HTTP Interface Authentication
173 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Monitor
174 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Network I/O
175 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: REST Interface
176 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Audio REST Interface
177 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Authentication Support for the REST Interface
178 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: REST Interface :: Core
179 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: REST mDNS Announcer
180 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Sitemap REST Interface
181 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: SSE Interface
182 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: REST Interface :: Swagger 1
183 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Transformation REST Interface
184 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: UI REST Interface
185 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Voice REST Interface
186 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: mDNS Service
187 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: WebSocket
188 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Karaf Integration
189 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Core
190 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Items
191 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Item IDE
192 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Items Runtime
193 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Language Server
194 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Persistence
195 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Persistence IDE
196 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Persistence Runtime
197 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Rules
198 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Rule IDE
199 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Rules Runtime
200 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Script
201 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Script IDE
202 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Script Runtime
203 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Sitemap
204 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Sitemap IDE
205 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Sitemap Runtime
206 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Thing
207 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Thing IDE
208 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Model Thing Runtime
209 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Persistence
210 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Semantics
211 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: JSON Storage
212 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Thing
213 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Transformation Service
214 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: UI
215 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: UI Icon Support
216 │ Active │  80 │ 4.0.2                  │ openHAB Core :: Bundles :: Voice
217 │ Active │  80 │ 4.0.2                  │ openHAB UI :: Bundles :: Main UI
218 │ Active │  80 │ 4.0.2                  │ openHAB UI :: Bundles :: Icon Set :: Classic
228 │ Active │  80 │ 1.0.0.201802012106     │ org.osgi:org.osgi.service.jaxrs
229 │ Active │  80 │ 1.5.0                  │ ThreeTen-Extra
230 │ Active │  80 │ 1.33.0                 │ SnakeYAML
231 │ Active │  80 │ 2.1                    │ SI Units
232 │ Active │  80 │ 2.1.0                  │ SI Quantities
233 │ Active │  80 │ 4.2.1                  │ Stax2 API
234 │ Active │  80 │ 2.1.2                  │ Units of Measurement Reference Implementation
235 │ Active │  80 │ 2.1.0                  │ Units of Measurement Common Library for Java
236 │ Active │  80 │ 1.4.20                 │ XStream Core
237 │ Active │  80 │ 4.0.0.202308012303     │ openHAB Add-ons :: Bundles :: Voice :: HABSpeaker
238 │ Active │  80 │ 3.4.0.202208181630     │ openHAB Add-ons :: Bundles :: SolarForecast Binding
239 │ Active │  80 │ 4.0.2                  │ openHAB Add-ons :: Bundles :: Voice :: Vosk Speech to Text

Update.log:

mage and userdata versions differ! Starting an upgrade.
You can find backup of userdata in /openhab/userdata/backup/userdata-2023-08-16T10-35-33.tar

################################################
          openHAB Docker update script          
################################################

The script will attempt to update openHAB to version 4.0.2
Please read the following notes and warnings:


Performing pre-update tasks for version 4.0.2:
  Adding '.bak' to /openhab/userdata/etc/log4j2.xml
  Using default file /openhab/userdata/etc/log4j2.xml
Replacing userdata system files with newer versions...
Clearing cache...

Starting JSON database update...
[main] INFO org.openhab.core.tools.internal.Upgrader - Already executed 'itemCopyUnitToMetadata' on 2023-07-30T09:16:28.459864750+02:00[Europe/Zurich]. Use '--force'  to execute it again.
[main] INFO org.openhab.core.tools.internal.Upgrader - Already executed 'linkUpgradeJsProfile' on 2023-07-30T09:16:28.512855530+02:00[Europe/Zurich]. Use '--force'  to execute it again.
JSON database updated successfully.


SUCCESS: openHAB updated from 4.0.1 to 4.0.2

rlkoshak · August 16, 2023, 1:53pm

The only errors I see in these logs are caused by the fact that at least one rule is being triggered before the Nashorn add-on is reinstalled as part of the upgrade (or maybe it’s not installed at all?). That wouldn’t be unusual after the first boot after an upgrade if the network is slow or the download of the new add-ons takes some time for other reasons.

I don’t remember what the Error:Handler state for a Thing means but I think that too is related to the add-on not being installed or available. Looking at your list of bundles, indeed, I do not see any of these add-ons as being listed as installed.

Assuming you’ve started OH and given it plenty of time to come up and download all the required add-ons, the next step I think will be reinstall those add-ons manually. You should be able to do that through MainUI the same way you installed them initially.

Note: you are mounting a volume that captures userdata/config outside of the container, right? That’s where the installed add-ons config gets saved.

Scriptwriter · August 16, 2023, 2:12pm

Hi Rich,
thanks you. This was a good hint. I dont know why they are no more available.

From the error i got from some googling to clean the caches to avoid something wrong in there:

docker-compose stop
rm -fr openhab_userdata/cache/*
rm -fr openhab_userdata/tmp/*
docker-compose up -d

after that and redownload all bindings they come again to Online-state.
I never had this before on an update that i lost the bindings.
im mounting into container the following path:
- “/etc/localtime:/etc/localtime:ro”
- “/etc/timezone:/etc/timezone:ro”
- “openhab_addons:/openhab/addons”
- “openhab_conf:/openhab/conf”
- “openhab_userdata:/openhab/userdata”
- “/sys/bus/w1/devices:/sys/bus/w1/devices”
so maybe something changed with pathes where the bindings in there…

rlkoshak · August 16, 2023, 2:17pm

No, your mounts look OH. I couldn’t begin to guess why your add-ons didn’t get installed. If it ever happens again, we’ll want to look into it. At this point all I can recommend is to give OH time to come up and install everything that first time after an upgrade. It can sometimes take quite some time.

Scriptwriter · August 16, 2023, 2:23pm

…it did not install any lost binding itself in the last 5 hours. Also i greped for errors in openhab.log and nothing was reportet from unsuccessful download or something from bindings (only the javascript from engine not yet reinstalled) so from my opinion it could also be that it wasnt initiated automaticly. But if someone else the same problem appeared he/she could write a notice here to see if it is a generally problem. For me its solved by the manual action

rlkoshak · August 16, 2023, 2:27pm

But you said you rebooted. It might be the case that if the installation of the add-ons were interrupted during that reboot they became corrupted. Clearing the cache was exactly the right remedy if that was the case.

I don’t think we have enough details to really know what happened. I’m just making educated guesses.

s0170071 · August 18, 2023, 10:36am

I switched over to 4.0.2. (docker) It started ok from what I could see in the console. But I cannot get any other response out of it - neither the browser log nor the UI. Switching back to 3.x - everything back to normal.
I also tried 4.0.1 which did start (incl. UI) but often lost the connection to my homematic binding.

wborn · August 18, 2023, 11:30am

Please create your own post @s0170071 and provide detailed logging and what you already tried to resolve it.

s0170071 · August 19, 2023, 9:14am

Actually I did solve it:

Sorry for the hijacking attempt

Scriptwriter · August 28, 2023, 1:15pm

today i had the same problem again. All addons were lost. The only thing what happened was a restart.

What i also dont understand: - “openhab_addons:/openhab/addons” The Folder itself is empty:
docker exec -it openhab_openhab_1 ls -la /openhab/addons
total 12
drwxr-xr-x 2 openhab openhab 4096 Aug 28 15:14 .
drwxr-xr-x 1 openhab openhab 4096 Aug 16 03:47 …

Where are the cached Bindings? What can i do?

rlkoshak · August 28, 2023, 1:35pm

Cached bindings are in $OH_USERDATA/cache. The addons folder is only a place to put .jar and .kar files to install addons manually instead of through OH itself. For most users that folder remains and will forever remain empty.

Watch $OH_USERDATA/logs/update.log. Is it doing an update prior to when you lose the add-ons? An update includes a clearing of the cache which forces a reinstallation of all the add-ons. You want this to happen when the version of OH changes, but no on every startup.

One thing you can do to lessen the impact of this problem is to download the .kar file with all the addons from the download page and drop that into the addons folder. Instead of reaching out to the internet to download the add-ons it will pull from that .kar file. However, it’ll be up to you to ensure that .kar file always matches your OH version. And of course it does nothing to solve the root problem.

Scriptwriter · August 28, 2023, 1:46pm

Hi Rich,
Thanks. In the update.log is exactly same what i copied in first post of this case.

The newly downloaded bindings are in there (also outside container on the volume whih i verified).

Thanks for the workaround with the kar files which i will do if it happens again.

So something seems there which is cleaning this cache from whatever reason. Can i do something to find out from what this comes? In openhab.log there was no hint.

As i told i had such behavior never before 4.0.2. You know from changes which impacting such kind of behavior?

rlkoshak · August 28, 2023, 1:55pm

There wouldn’t be anything there. OH doesn’t clean out it’s own cache. That always comes from somewhere external.

In Docker the only thing that clears the cache is the entrypoint.sh script which only does that if it detects that the version of OH running in the container is different from the version specified in the configs, specifically $OH_USERDATA/etc/version.properties. When the versions are different it makes a backup of userdata ($OH_USERDATA/backup), deletes the contents of cache and tmp (clearing the cache) and replaces etc with the defaults (with some exceptions, I don’t think it replaces log4j2.xml, users.properties, and similar files which are likely to be customized by end users). You should see these briefly mentioned in update.log. Here is my most recent update from a week ago.

Image and userdata versions differ! Starting an upgrade.
You can find backup of userdata in /openhab/userdata/backup/userdata-2023-08-22T10-21-50.tar

################################################
          openHAB Docker update script
################################################

The script will attempt to update openHAB to version 4.1.0-SNAPSHOT
Please read the following ESC[32mnotesESC[m and ESC[31mwarningsESC[m:

Replacing userdata system files with newer versions...
Clearing cache...

Starting JSON database update...
[main] INFO org.openhab.core.tools.internal.Upgrader - Already executed 'itemCopyUnitToMetadata' on 2023-05-25T10:39:15.030364826-06:00[America/Denver]. Use '--force'  to execute it again.
[main] INFO org.openhab.core.tools.internal.Upgrader - Already executed 'linkUpgradeJsProfile' on 2023-05-25T10:39:15.085525400-06:00[America/Denver]. Use '--force'  to execute it again.
JSON database updated successfully.


SUCCESS: openHAB updated from 4.1.0-SNAPSHOT to 4.1.0-SNAPSHOT

There will not be an update.log file at all in cases where you’ve started a container that matches the version of the configs.

Outside of that, if something is deleting these folders it’s outside of openHAB and the container.

Scriptwriter · August 28, 2023, 2:05pm

docker exec -it openhab_openhab_1 ls -la /openhab/userdata/etc/version.properties
-rw-r--r-- 1 openhab openhab 342 Aug 16 10:35 /openhab/userdata/etc/version.properties

The date matches the date of the update.log and the beginning of this thread…

Outside container are only Backupscripts and to the server no other persons should have access

So its very mysterious…

rlkoshak · August 28, 2023, 2:12pm

SD or SSD? Sudden loss of power instead of a normal shutdown?

Scriptwriter · August 28, 2023, 2:14pm

… no powerloss, no reboot, only containerrestart. Its an ssd

docker ps |grep openhab_openhab_1
ffa033886a19   local/openhab:latest             "/entrypoint gosu op…"   2 hours ago    Up 2 hours (healthy)                                                                                                                                                                                                                                                                                                                                                                                      openhab_openhab_1
uptime -s
2023-08-25 17:20:27

rlkoshak · August 28, 2023, 2:16pm

When all other problems are eliminated, a health check on the file system/storage is prudent. I’ve got nothing else.

Scriptwriter · August 28, 2023, 2:47pm

interesting: The count of directories in cache and on screenshot of webgui of installed bindings are mismatching

docker exec -it openhab_openhab_1 ls -la /openhab/userdata/cache
total 44
drwxr-xr-x   7 openhab openhab  4096 Aug 24 08:18 .
drwxr-xr-x  22 openhab openhab  4096 Aug 23 09:59 ..
-rw-r--r--   1 openhab openhab 13089 Aug 24 08:18 1692772817522.log
drwxr-xr-x 283 openhab openhab  4096 Aug 28 16:25 org.eclipse.osgi
drwxr-xr-x   2 openhab openhab  4096 Aug 16 17:32 org.openhab.binding.chromecast
drwxr-xr-x   2 openhab openhab  4096 Aug 28 10:27 org.openhab.binding.icalendar
drwxr-xr-x   2 openhab openhab  4096 Aug 16 17:31 org.openhab.binding.openweathermap
drwxr-xr-x   2 openhab openhab  4096 Aug 23 10:00 org.openhab.voice.tts

There are definitively more bindings installed which the Screenshot shows.
And the as installed shown bindings are working but i dont know where they are installed if not in cache-folder…

rlkoshak · August 28, 2023, 2:53pm

Not every add-on gets it’s own root folder. I’ve never had this problem and I’ve only the following:

rich@argus:/s/o/userdata (main) ✗ 👁️  ls -l cache
total 24
drwxr-xr-x 332 openhab openhab  4096 Aug 24 09:30 org.eclipse.osgi
drwxr-xr-x   2 openhab openhab 12288 Aug 28 06:46 org.openhab.binding.chromecast
drwxr-xr-x   2 openhab openhab  4096 Aug 28 00:32 org.openhab.binding.openweathermap
drwxr-xr-x   2 openhab openhab  4096 Aug 22 10:34 org.openhab.voice.tts

It looks like the rest show up under tmp/mvn/org/openhabn.addons/bundles

rich@argus:/s/o/userdata (main) ✗ 👁️  cd tmp/mvn/org/openhab/addons/bundles/
rich@argus:/s/o/u/t/m/o/o/a/bundles (main) ✗ 👁️  ls
org.openhab.automation.jsscripting     org.openhab.binding.mqtt.espmilighthub  org.openhab.binding.roku                      org.openhab.binding.zigbee.ember      org.openhab.persistence.rrd4j
org.openhab.binding.amazonechocontrol  org.openhab.binding.mqtt.generic        org.openhab.binding.shelly                    org.openhab.binding.zigbee.firmware   org.openhab.transform.jinja
org.openhab.binding.astro              org.openhab.binding.mqtt.homeassistant  org.openhab.binding.vesync                    org.openhab.binding.zigbee.serial     org.openhab.transform.jsonpath
org.openhab.binding.chromecast         org.openhab.binding.mqtt.homie          org.openhab.binding.zigbee                    org.openhab.binding.zigbee.telegesis  org.openhab.transform.map
org.openhab.binding.http               org.openhab.binding.mqtt.ruuvigateway   org.openhab.binding.zigbee.cc2531             org.openhab.binding.zigbee.xbee       org.openhab.transform.regex
org.openhab.binding.ipcamera           org.openhab.binding.network             org.openhab.binding.zigbee.console            org.openhab.binding.zwave             org.openhab.voice.googletts
org.openhab.binding.mail               org.openhab.binding.networkupstools     org.openhab.binding.zigbee.console.ember      org.openhab.io.openhabcloud
org.openhab.binding.mqtt               org.openhab.binding.openweathermap      org.openhab.binding.zigbee.console.telegesis  org.openhab.persistence.mapdb

Scriptwriter · August 28, 2023, 3:01pm

more differences with this folder:

docker exec -it openhab_openhab_1 ls -la /openhab/userdata/tmp/mvn/org/openhab/addons/bundles
total 144
drwxr-xr-x 36 openhab openhab 4096 Aug 28 11:19 .
drwxr-xr-x  4 openhab openhab 4096 Aug 23 09:59 ..
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:01 org.openhab.automation.jsscripting
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:48 org.openhab.automation.jsscriptingnashorn
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:27 org.openhab.binding.astro
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:32 org.openhab.binding.chromecast
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:41 org.openhab.binding.dsmr
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:28 org.openhab.binding.feed
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:33 org.openhab.binding.gpstracker
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:32 org.openhab.binding.hpprinter
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:06 org.openhab.binding.http
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:05 org.openhab.binding.icalendar
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:28 org.openhab.binding.ipcamera
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:01 org.openhab.binding.knx
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:39 org.openhab.binding.mail
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:03 org.openhab.binding.network
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:03 org.openhab.binding.onewire
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:25 org.openhab.binding.onewiregpio
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:31 org.openhab.binding.openweathermap
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:31 org.openhab.binding.publictransportswitzerland
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:40 org.openhab.binding.pulseaudio
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:02 org.openhab.binding.smartmeter
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:31 org.openhab.binding.snmp
drwxr-xr-x  3 openhab openhab 4096 Aug 28 11:11 org.openhab.binding.telegram
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:03 org.openhab.binding.unifi
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:26 org.openhab.binding.upnpcontrol
drwxr-xr-x  3 openhab openhab 4096 Aug 16 16:32 org.openhab.binding.yamahareceiver
drwxr-xr-x  3 openhab openhab 4096 Aug 18 10:47 org.openhab.io.metrics
drwxr-xr-x  3 openhab openhab 4096 Aug 23 08:50 org.openhab.io.openhabcloud
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:43 org.openhab.persistence.influxdb
drwxr-xr-x  3 openhab openhab 4096 Aug 18 10:51 org.openhab.transform.jsonpath
drwxr-xr-x  3 openhab openhab 4096 Aug 18 10:52 org.openhab.transform.regex
drwxr-xr-x  3 openhab openhab 4096 Aug 28 11:19 org.openhab.voice.marytts
drwxr-xr-x  3 openhab openhab 4096 Aug 23 09:59 org.openhab.voice.picotts
drwxr-xr-x  3 openhab openhab 4096 Aug 23 09:59 org.openhab.voice.voicerss
drwxr-xr-x  3 openhab openhab 4096 Aug 16 15:57 org.openhab.voice.voskstt
root@dockerpi01:~/openhab# docker exec -it openhab_openhab_1 ls -la /openhab/userdata/tmp/mvn/org/openhab/addons/bundles/org.openhab.binding.dsmr
total 12
drwxr-xr-x  3 openhab openhab 4096 Aug 16 17:41 .
drwxr-xr-x 36 openhab openhab 4096 Aug 28 11:19 ..
drwxr-xr-x  2 openhab openhab 4096 Aug 16 17:41 4.0.2
root@dockerpi01:~/openhab# docker exec -it openhab_openhab_1 ls -la /openhab/userdata/tmp/mvn/org/openhab/addons/bundles/org.openhab.binding.dsmr/4.0.2
total 164
drwxr-xr-x 2 openhab openhab   4096 Aug 16 17:41 .
drwxr-xr-x 3 openhab openhab   4096 Aug 16 17:41 ..
-rw-r--r-- 1 openhab openhab 151694 Aug 16 17:41 org.openhab.binding.dsmr-4.0.2.jar
-rw-r--r-- 1 openhab openhab     40 Aug 16 17:41 org.openhab.binding.dsmr-4.0.2.jar.sha1

i picked out one binding: dsmr

filesystem in container shows the files, but gui tells its not installed.

docker exec -it openhab_openhab_1 sha1sum /openhab/userdata/tmp/mvn/org/openhab/addons/bundles/org.openhab.binding.dsmr/4.0.2/org.openhab.binding.dsmr-4.0.2.jar
85782d812851850e21d580e4a4d4fcabd331e7fa

and the sum in the sha1 file shows 85782d812851850e21d580e4a4d4fcabd331e7fa so it seems the correct file