Clean install - OH3 service won't start

sebasanblas · February 18, 2021, 7:07pm

Platform information:
- Hardware: Raspberry Ppi 3 B+
- OS: Raspbian GNU/Linux 10 (buster) - K: Linux 5.10.11-v7+
- Java Runtime Environment: build 11.0.10+9-LTS
- openHAB version: 3.0.1-2

Days ago, I began to notice that if I restarted the RPi, openhab sometimes did not start, when I executed the command sudo systemctl restart openhab

I got this:

Warning: The unit file, source configuration file or drop-ins of openhab.service changed on disk. Run 'systemctl daemon-reload' to reload units.

After running openhab started with the same message…

I was investigating a little more with journalctl -u openhab.service -b

feb 18 09:58:34 openhabian systemd[1]: Started openHAB instance, reachable at http://openhabian:8080.
feb 18 09:58:35 openhabian systemd[1]: Stopping openHAB instance, reachable at http://openhabian:8080...
feb 18 09:58:45 openhabian karaf[662]: Can't connect to the container. The container is not running.
feb 18 09:58:45 openhabian systemd[1]: openhab.service: Control process exited, code=exited, status=1/FAILURE
feb 18 09:58:45 openhabian systemd[1]: openhab.service: Failed with result 'exit-code'.
feb 18 09:58:45 openhabian systemd[1]: Stopped openHAB instance, reachable at http://openhabian:8080.
feb 18 10:42:09 openhabian karaf[1353]: WARNING: An illegal reflective access operation has occurred
feb 18 10:42:09 openhabian karaf[1353]: WARNING: Illegal reflective access by com.google.gson.internal.bind.ReflectiveTypeAdapterFactory (file:/var/lib/openhab/cach
feb 18 10:42:09 openhabian karaf[1353]: WARNING: Please consider reporting this to the maintainers of com.google.gson.internal.bind.ReflectiveTypeAdapterFactory
feb 18 10:42:09 openhabian karaf[1353]: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
feb 18 10:42:09 openhabian karaf[1353]: WARNING: All illegal access operations will be denied in a future release
feb 18 15:27:18 openhabian systemd[1]: Stopping openHAB instance, reachable at http://openhabian:8080...
feb 18 15:27:31 openhabian systemd[1]: openhab.service: Succeeded.
feb 18 15:27:31 openhabian systemd[1]: Stopped openHAB instance, reachable at http://openhabian:8080.
feb 18 15:27:31 openhabian systemd[1]: Started openHAB instance, reachable at http://openhabian:8080.
feb 18 15:33:03 openhabian systemd[1]: Stopping openHAB instance, reachable at http://openhabian:8080...
feb 18 15:33:10 openhabian karaf[9486]: org.osgi.framework.BundleException: Unable to acquire the state change lock for the module: osgi.identity; type="osgi.bundle
feb 18 15:33:10 openhabian karaf[9486]:         at org.eclipse.osgi.container.Module.lockStateChange(Module.java:337)
feb 18 15:33:10 openhabian karaf[9486]:         at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule.asyncStop(EquinoxBundle.java:1
feb 18 15:33:10 openhabian karaf[9486]:         at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle.stop(EquinoxBundle.java:262)
feb 18 15:33:10 openhabian karaf[9486]:         at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle.stop(EquinoxBundle.java:267)
feb 18 15:33:10 openhabian karaf[9486]:         at org.eclipse.osgi.launch.Equinox.stop(Equinox.java:123)
feb 18 15:33:10 openhabian karaf[9486]:         at org.apache.karaf.main.Main$2.run(Main.java:354)
feb 18 15:33:10 openhabian karaf[9486]: Caused by: java.util.concurrent.TimeoutException: Timeout after waiting 5 seconds to acquire the lock.
feb 18 15:33:10 openhabian karaf[9486]:         at org.eclipse.osgi.container.Module.lockStateChange(Module.java:334)
feb 18 15:33:10 openhabian karaf[9486]:         ... 5 more
feb 18 15:33:16 openhabian systemd[1]: openhab.service: Succeeded.
feb 18 15:33:16 openhabian systemd[1]: Stopped openHAB instance, reachable at http://openhabian:8080.
feb 18 15:33:16 openhabian systemd[1]: Started openHAB instance, reachable at http://openhabian:8080.
feb 18 15:41:43 openhabian karaf[10016]: WARNING: An illegal reflective access operation has occurred
feb 18 15:41:43 openhabian karaf[10016]: WARNING: Illegal reflective access by com.google.gson.internal.bind.ReflectiveTypeAdapterFactory (file:/var/lib/openhab/cac
feb 18 15:41:43 openhabian karaf[10016]: WARNING: Please consider reporting this to the maintainers of com.google.gson.internal.bind.ReflectiveTypeAdapterFactory
feb 18 15:41:43 openhabian karaf[10016]: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
feb 18 15:41:43 openhabian karaf[10016]: WARNING: All illegal access operations will be denied in a future release

After sudo shutdown -r now:

Warning: The unit file, source configuration file or drop-ins of openhab.service changed on disk. Run 'systemctl daemon-reload' to reload units.
● openhab.service - openHAB instance, reachable at http://openhabian:8080
   Loaded: loaded (/lib/systemd/system/openhab.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/openhab.service.d
           └─override.conf
   Active: failed (Result: exit-code) since Thu 2021-02-18 15:57:12 -03; 9min ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
  Process: 528 ExecStart=/usr/share/openhab/runtime/bin/karaf ${OPENHAB_STARTMODE} (code=exited, status=143)
  Process: 585 ExecStop=/usr/share/openhab/runtime/bin/karaf stop (code=exited, status=1/FAILURE)
 Main PID: 528 (code=exited, status=143)

feb 18 15:57:02 openhabian systemd[1]: Started openHAB instance, reachable at http://openhabian:8080.
feb 18 15:57:02 openhabian systemd[1]: Stopping openHAB instance, reachable at http://openhabian:8080...
feb 18 15:57:12 openhabian karaf[585]: Can't connect to the container. The container is not running.
feb 18 15:57:12 openhabian systemd[1]: openhab.service: Control process exited, code=exited, status=1/FAILURE
feb 18 15:57:12 openhabian systemd[1]: openhab.service: Failed with result 'exit-code'.
feb 18 15:57:12 openhabian systemd[1]: Stopped openHAB instance, reachable at http://openhabian:8080

I really don’t know what might be causing this (I thought it was spotify binding so I disabled it but the problem persists).

I find it important to note that it was a clean installation of oh3.

Any ideas? Thanks!

sebasanblas · February 19, 2021, 10:56am

On another SD card, with clean installation, I received:

sudo systemctl status openhab.service 

We trust you have received the usual lecture from the local System
Administrator. It usually boils down to these three things:

    #1) Respect the privacy of others.
    #2) Think before you type.
    #3) With great power comes great responsibility.

[sudo] password for openhabian: 
Warning: The unit file, source configuration file or drop-ins of openhab.service changed on disk. Run 'systemctl daemon-reload' to reload units.
● openhab.service - openHAB instance, reachable at http://openhabian:8080
   Loaded: loaded (/lib/systemd/system/openhab.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/openhab.service.d
           └─override.conf
   Active: active (running) since Fri 2021-02-19 06:35:34 CET; 5h 16min ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
 Main PID: 1430 (java)
    Tasks: 99 (limit: 2182)
   CGroup: /system.slice/openhab.service
           └─1430 /usr/bin/java -XX:-UsePerfData -Dopenhab.home=/usr/share/openhab -Dopenhab.conf=/etc/openhab -Dopenhab.runtime=/usr/share/openhab/runtime -Dopenha(.....)