OH4.0.2 not starting after upgrade

Hi,

I’m running docker image and upgraded from 3.4.4 to 4.0.2 . In the start logs it showed it was upgraded successfully, then it went to start OH but nothing happens. openhab.log stays empty, OH does not start, website is not available. I’ve entered the docker image and connected to karaf but that does not look like it has been filled with OH stuff.

Restarting the container does not help. No upgrade in the startup log, and just logging Launching the openHAB runtime..

I have no log what so ever to consult so I have no idea what to do.

Any help is much appreciated.

Thanks,
Bastiaan

If it did the upgrade successfully you should find an update.log in userdata/logs with any errors that may have occurred during the upgrade. You will not find anything in openhab.log nor in events.log.

Hopefully you have a backup and can try again and either watch the logs using docker logs -f openhab.

Hi, it did create the update.log. Prior for the upgrade I made backups, I have executed the upgrade twice (on restored backup) with the same end result having OH 4.0.2 which upgrades but does not start the runtime. After 10 minutes the docker status goes to not healthy. Restarting the container does not trigger the upgrade anymore but also hangs at starting the runtime with no logs and no accessable webinterface.

update.log

Image and userdata versions differ! Starting an upgrade.
You can find backup of userdata in /openhab/userdata/backup/userdata-2023-08-29T19-16-50.tar

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

The script will attempt to update openHAB to version 4.0.2
Please read the following e[32mnotese[m and e[31mwarningse[m:

Important notes for version 4.0.0:
  e[31mWarning:e[m  CORE: core.GenericEventTrigger and core.GenericEventCondition parameters have have changed. See https://www.openhab.org/docs/configuration/rules-ng.html#system-module-types.
  e[31mWarning:e[m  CORE: Rules are now triggered by ItemStateUpdatedEvent instead of ItemStateEvent. If you use JSR223 scripting without helper libraries and expect a certain Java type, code changes might be needed.
  e[31mWarning:e[m  CORE: The syntax for an item category/icon in a textual configuration file no longer accepts a value enclosed in quotes. So <temperature> is valid but not <"temperature">. Please update the definition of your items if necessary.
  e[31mWarning:e[m  CORE: SCRIPT transformation has been removed and replaced with language-specific transformations: JS, RB, PY, DSL, GROOVY, etc. See https://www.openhab.org/docs/configuration/transformations.html#script-transformation
  e[31mWarning:e[m  CORE: UoM has been refactored. Please consult https://www.openhab.org/docs/concepts/units-of-measurement.html and https://www.openhab.org/docs/installation/#upgrading BEFORE starting openHAB, otherwise your persisted data may be corrupted.
  e[31mWarning:e[m  Airthings Binding: The channels `radon_st_avg` and `radon_lt_avg` are now of dimension `RadiationSpecificActivity` instead of `Density`. Please update your linked items accordingly.
  e[31mWarning:e[m  Bosch Indego Binding: Due to changes in the cloud services, the authentication method has changed. Please follow the authorization flow described in the documentation. Furthermore, a bridge is now required and must be assigned to the `indego` thing. Configuration of username and password is no longer required/supported.
  e[31mWarning:e[m  ComfoAir Binding: The channel `enthalpy#enthalpyTime` now represents the set time (in minutes) instead of the internal number value that is sent to the device (`minutes / 12`).
  e[31mWarning:e[m  DanfossAirUnit Binding: The deprecated channel 'manual_fan_speed' has been removed. Please use channel 'manual_fan_step' introduced in 3.2.
  e[31mWarning:e[m  Dark Sky Binding: Due to EOL of their API, this add-on has been removed.
  e[31mWarning:e[m  Generac MobileLink Binding: Due to an API change, existing Generator Things will need to be deleted and added again. Additionally, existing Items will need to be adjusted to reflect the updated Generator Thing channels.
  e[31mWarning:e[m  HomeKit: Add-on wide configuration of mappings for thermostat modes is no longer supported. Please use item-level configuration as described in the README.
  e[31mWarning:e[m  Hue emulation: The uniqueid value has been changed to resolve discovery issues with Alexa. You may need to rediscover "devices" in all services that use the hue emulation (Amazon Echo, Logitech Harmony, etc).
  e[31mWarning:e[m  Hunter Douglas (Luxaflex) PowerView Binding: Deprecated scene channels have been removed. Please use the scene channels introduced in 3.2 (in channel group 'scenes').
  e[31mWarning:e[m  JavaScript: JavaScript engines have changed their MIME types: NashornJS is application/javascript:version=ECMAScript-5.1 and GraalJS is application/javascript. Please update your scripts to either make them compatible with GraalJS or change the MIME type to continue to use NashornJS. For Blockly migration, visit the Blockly documentation.
  e[31mWarning:e[m  JavaScript NashornJS: NashornJS has been removed from core and isn't included by default. If you still need or want to use it, you can install it as an addon.
  e[31mWarning:e[m  JavaScript Scripting Automation: The old "metadata" and "itemchannellink" APIs have been replaced by a new API with extended functionality on the "items" namespace.
  e[31mWarning:e[m  JavaScript Scripting Automation: ItemHistory: historicState, maximumBetween, maximumSince, minimumBetween, minimumSince & previousState now return a HistoricItem instead of just the state. previousStateTimestamp has been removed, the timestamp is available on the HistoricItem.
  e[31mWarning:e[m  KNX Binding: Units of Measurements have been introduced, make sure you use correct units in the state description. Rules may need to be adapted. Several items changed from PercentType to QuantityType, i.e. raw values increase by a factor of 100.
  e[31mWarning:e[m  LuftdatenInfo Binding: The binding was renamed to Sensor.Community Binding to match the new naming of the service. Things need to be recreated.
  e[31mWarning:e[m  Netatmo Binding: Due to API authorization process change scheduled on the 2023/04/17 - refresh Token is no more stored in thing configuration, thus can be removed from things config files. If it remains, it'll be ignored.
  e[31mWarning:e[m  Netatmo Binding: New scope has been added for the introduction of the Carbon Monoxide Alarm. Authorization process has to be replayed (and former refreshToken can be removed from things config files -- see above).
  e[31mWarning:e[m  Windcentrale Binding: The binding has been reworked to support the new API that requires authentication. Delete old 'mill' Things, add an 'account' Bridge and add new 'windmill' Things using the 'account' as Bridge. The channel names now follow the naming conventions. Items must be adapted for these changes.


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...

Performing post-update tasks for version 4.0.0:
  Replacing: String ,javascript to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String javascript, to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String javascript to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String ,cometvisu-php to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String cometvisu-php, to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String cometvisu-php to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String ,innogysmarthome to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String innogysmarthome, to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String innogysmarthome to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String ,imperihome to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String imperihome, to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String imperihome to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String ,darksky to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String darksky, to  in file /openhab/userdata/config/org/openhab/addons.config
  Replacing: String darksky to  in file /openhab/userdata/config/org/openhab/addons.config

Starting JSON database update...
[main] INFO org.openhab.core.tools.internal.Upgrader - Already executed 'itemCopyUnitToMetadata' on 2023-07-31T20:25:12.776911665Z[Etc/UTC]. Use '--force'  to execute it again.
[main] INFO org.openhab.core.tools.internal.Upgrader - Already executed 'linkUpgradeJsProfile' on 2023-07-31T20:25:12.837050049Z[Etc/UTC]. Use '--force'  to execute it again.
JSON database updated successfully.


SUCCESS: openHAB updated from 3.4.4 to 4.0.2

At starting the runtime this is the remaining service which stays like this indefinitely

/usr/lib/jvm/java-17-openjdk-amd64/bin/java -XX:-UsePerfData -Dopenhab.home=/openhab -Dopenhab.conf=/openhab/conf -Dopenhab.runtime=/openhab/runtime -Dopenhab.userdata=/openhab/userdata -Dopenhab.logdir=/openhab/userdata/logs -Dfelix.cm.dir=/openhab/userdata/config -Djava.library.path=/openhab/userdata/tmp/lib -Djdk.util.zip.disableZip64ExtraFieldValidation=true -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dorg.apache.cxf.osgi.http.transport.disable=true -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -Dfile.encoding=UTF-8 -XX:+UseG1GC -Duser.timezone=Europe/Amsterdam --add-reads=java.xml=java.logging --add-exports=java.base/org.apache.karaf.specs.locator=java.xml,ALL-UNNAMED --patch-module java.base=/openhab/runtime/lib/endorsed/org.apache.karaf.specs.locator-4.4.3.jar --patch-module java.xml=/openhab/runtime/lib/endorsed/org.apache.karaf.specs.java.xml-4.4.3.jar --add-opens java.base/java.security=ALL-UNNAMED --add-opens java.base/java.net=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.naming/javax.naming.spi=ALL-UNNAMED --add-opens java.rmi/sun.rmi.transport.tcp=ALL-UNNAMED --add-opens java.base/java.io=ALL-UNNAMED --add-opens java.base/java.lang.reflect=ALL-UNNAMED --add-opens java.base/java.text=ALL-UNNAMED --add-opens java.base/java.time=ALL-UNNAMED --add-opens java.desktop/java.awt.font=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.file=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.ftp=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.https=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.jar=ALL-UNNAMED --add-exports=java.base/sun.net.www.content.text=ALL-UNNAMED --add-exports=jdk.xml.dom/org.w3c.dom.html=ALL-UNNAMED --add-exports=jdk.naming.rmi/com.sun.jndi.url.rmi=ALL-UNNAMED --add-exports=java.rmi/sun.rmi.registry=ALL-UNNAMED --add-exports=java.security.sasl/com.sun.security.sasl=ALL-UNNAMED --add-exports=java.naming/com.sun.jndi.ldap=ALL-UNNAMED -Dkaraf.instances=/openhab/userdata/tmp/instances -Dkaraf.home=/openhab/runtime -Dkaraf.base=/openhab/userdata -Dkaraf.data=/openhab/userdata -Dkaraf.etc=/openhab/userdata/etc -Dkaraf.log=/openhab/userdata/logs -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/openhab/userdata/tmp -Djava.util.logging.config.file=/openhab/userdata/etc/java.util.logging.properties -Dkaraf.startLocalConsole=false -Dkaraf.startRemoteShell=true -classpath /openhab/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.4.3.jar:/openhab/runtime/lib/boot/org.apache.karaf.jaas.boot-4.4.3.jar:/openhab/runtime/lib/boot/org.apache.karaf.main-4.4.3.jar:/openhab/runtime/lib/boot/org.apache.karaf.specs.activator-4.4.3.jar:/openhab/runtime/lib/boot/osgi.core-8.0.0.jar:/openhab/runtime/lib/jdk9plus/istack-commons-runtime-3.0.10.jar:/openhab/runtime/lib/jdk9plus/jakarta.xml.bind-api-2.3.3.jar:/openhab/runtime/lib/jdk9plus/javax.annotation-api-1.3.2.jar:/openhab/runtime/lib/jdk9plus/jaxb-runtime-2.3.3.jar:/openhab/runtime/lib/jdk9plus/org.apache.servicemix.specs.activation-api-1.2.1-1.2.1_3.jar:/openhab/runtime/lib/jdk9plus/txw2-2.3.3.jar org.apache.karaf.main.Main

And when you start it what do you see in docker logs -f openhab?

I just did a test on the non starting upgraded 4.0.2 container, I pulled the conf and userdata volumes and replaced it with empty ones. Then the container will start the runtime, logs are created and I can access the webservice. So it has something to do whats in my upgraded conf and/or userdata.

Here’s the docker log of the first start of 4.0.2 on 3.4.4 conf and userdata:

# docker logs -f openhab
+ IFS='
        '
++ ls -d /usr/lib/jvm/java-1.11.0-openjdk-amd64 /usr/lib/jvm/java-11-openjdk-amd64
++ tail -n 1
+ export JAVA_HOME=/usr/lib/jvm/java-11-openjdk-amd64
+ JAVA_HOME=/usr/lib/jvm/java-11-openjdk-amd64
+ '[' limited = unlimited ']'
+ capsh --print
+ grep -E Current:.+,cap_net_admin,cap_net_raw,.+
+ rm -f '/var/lock/LCK..*'
+ rm -f /openhab/userdata/tmp/instances/instance.properties
+ NEW_USER_ID=9001
+ NEW_GROUP_ID=9001
+ echo 'Starting with openhab user id: 9001 and group id: 9001'
Starting with openhab user id: 9001 and group id: 9001
+ id -u openhab
++ getent group 9001
+ '[' -z '' ']'
+ echo 'Create group openhab with id 9001'
+ groupadd -g 9001 openhab
Create group openhab with id 9001
Create user openhab with id 9001
+ echo 'Create user openhab with id 9001'
+ adduser -u 9001 --disabled-password --gecos '' --home /openhab --gid 9001 openhab
Warning: The home dir /openhab you specified already exists.
Adding user `openhab' ...
Adding new user `openhab' (9001) with group `openhab' ...
adduser: Warning: The home directory `/openhab' does not belong to the user you are currently creating.
The home directory `/openhab' already exists.  Not copying from `/etc/skel'.
+ groupadd -g 11 audio2
+ groupadd -g 14 uucp2
+ groupadd -g 16 dialout2
+ groupadd -g 17 audio3
+ groupadd -g 18 dialout3
+ groupadd -g 32 uucp3
+ groupadd -g 63 audio4
+ groupadd -g 490 dialout4
+ groupadd -g 492 audio5
+ groupadd -g 997 gpio
+ adduser openhab audio
Adding user `openhab' to group `audio' ...
Adding user openhab to group audio
Done.
+ adduser openhab audio2
Adding user `openhab' to group `audio2' ...
Adding user openhab to group audio2
Done.
+ adduser openhab audio3
Adding user `openhab' to group `audio3' ...
Adding user openhab to group audio3
Done.
+ adduser openhab audio4
Adding user `openhab' to group `audio4' ...
Adding user openhab to group audio4
Done.
+ adduser openhab audio5
Adding user `openhab' to group `audio5' ...
Adding user openhab to group audio5
Done.
+ adduser openhab dialout
Adding user `openhab' to group `dialout' ...
Adding user openhab to group dialout
Done.
+ adduser openhab dialout2
Adding user `openhab' to group `dialout2' ...
Adding user openhab to group dialout2
Done.
+ adduser openhab dialout3
Adding user `openhab' to group `dialout3' ...
Adding user openhab to group dialout3
Done.
+ adduser openhab dialout4
Adding user `openhab' to group `dialout4' ...
Adding user openhab to group dialout4
Done.
+ adduser openhab gpio
Adding user `openhab' to group `gpio' ...
Adding user openhab to group gpio
Done.
+ adduser openhab uucp
Adding user `openhab' to group `uucp' ...
Adding user openhab to group uucp
Done.
+ adduser openhab uucp2
Adding user `openhab' to group `uucp2' ...
Adding user openhab to group uucp2
Done.
+ adduser openhab uucp3
Adding user `openhab' to group `uucp3' ...
Adding user openhab to group uucp3
Done.
+ initialize_volume /openhab/conf /openhab/dist/conf
+ volume=/openhab/conf
+ source=/openhab/dist/conf
++ ls -A /openhab/conf
+ '[' -z 'automation
html
icons
items
persistence
rules
scripts
services
sitemaps
sounds
things
transform' ']'
+ initialize_volume /openhab/userdata /openhab/dist/userdata
+ volume=/openhab/userdata
+ source=/openhab/dist/userdata
++ ls -A /openhab/userdata
+ '[' -z 'backup
cache
Californium.properties
config
etc
hs_err_pid1127.log
hs_err_pid1296.log
hs_err_pid1302.log
hs_err_pid1345.log
hs_err_pid1605.log
hs_err_pid30034.log
jsondb
kar
logs
marketplace
mqtt
openhabcloud
persistence
secrets
tmp
uuid
voicerss
zwave' ']'
++ cmp /openhab/userdata/etc/version.properties /openhab/dist/userdata/etc/version.properties
+ '[' '!' -z ']'
+ chown -R openhab:openhab /openhab
+ sync
+ '[' -d /etc/cont-init.d ']'
+ sync
+ '[' false == false ']'
++ IFS=' '
++ echo gosu openhab tini -s ./start.sh
+ '[' 'gosu openhab tini -s ./start.sh' == 'gosu openhab tini -s ./start.sh' ']'
+ command=($@ server)
+ exec gosu openhab tini -s ./start.sh server
Launching the openHAB runtime...

How long have you waited after the upgrade for OH to come up? I’ve seen it take a few minutes. Beyond that I’ve got nothing. Once you see that "Launching " log statement you should start seeing stuff in openhab.log. But there are lot of differences between OH 3 and OH 4 and it can take a good bit of time to download and configure all the core parts from maven before OH even gets to that point.

I tought I waited long enough, tried a third upgrade and waited longer. Still nothing in openhab.log but suddenly I got access to the webservice. This took 10 minutes plus, very surprising on a SSD NUC with 4 cores and 200mbit fiber internet. Then after another 5 minutes the openhab.log began to fill.

I really did not expect this to take so long, I must have early aborted the other two times.

Anyhow, got it working, thanks for the help @rlkoshak, much appreciated.

The limitation is probably on the download server side.

I only found it to take that long when I upgraded from OH 3 to OH 4. After that updates happen way faster.