java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.manager/.fileTableLock

[matmai]

openhabian-config was upgraded from [master]v1.5-602(f254443) to [master]v1.5-684(4157102) and raspberrypi-kernel from (1.20200601-1) to (1.20200212-1). After upgrading to openHAB 2.5.6-2 via openhabian-config service did not start.

sudo systemctl status openhab2.service
● openhab2.service - openHAB 2 - empowering the smart home
   Loaded: loaded (/usr/lib/systemd/system/openhab2.service; enabled; vendor preset: enabled)
   Active: activating (auto-restart) (Result: exit-code) since Sun 2020-06-28 12:07:47 CEST; 4s ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
  Process: 30821 ExecStart=/usr/share/openhab2/runtime/bin/karaf ${OPENHAB_STARTMODE} (code=exited, status=255/EXCEPTION)
 Main PID: 30821 (code=exited, status=255/EXCEPTION)

Output from /var/log/openhab2/openhab.log /var/log/openhab2/events.log:

2020-06-28 12:07:47.029 [SCHWERWIEGEND] [org.apache.karaf.main.Main] - Could not launch framework
java.lang.RuntimeException: Error initializing storage.
    at org.eclipse.osgi.internal.framework.EquinoxContainer.<init>(EquinoxContainer.java:70)
    at org.eclipse.osgi.launch.Equinox.<init>(Equinox.java:31)
    at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFactory.java:24)
    at org.apache.karaf.main.Main.launch(Main.java:256)
    at org.apache.karaf.main.Main.main(Main.java:178)
Caused by: java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.manager/.fileTableLock (Keine Berechtigung)
    at java.io.RandomAccessFile.open0(Native Method)
    at java.io.RandomAccessFile.open(RandomAccessFile.java:316)
    at java.io.RandomAccessFile.<init>(RandomAccessFile.java:243)
    at org.eclipse.osgi.internal.location.Locker_JavaNio.lock(Locker_JavaNio.java:36)
    at org.eclipse.osgi.storagemanager.StorageManager.lock(StorageManager.java:388)
    at org.eclipse.osgi.storagemanager.StorageManager.open(StorageManager.java:701)
    at org.eclipse.osgi.storage.Storage.getChildStorageManager(Storage.java:1776)
    at org.eclipse.osgi.storage.Storage.getInfoInputStream(Storage.java:1793)
    at org.eclipse.osgi.storage.Storage.<init>(Storage.java:132)
    at org.eclipse.osgi.storage.Storage.createStorage(Storage.java:85)
    at org.eclipse.osgi.internal.framework.EquinoxContainer.<init>(EquinoxContainer.java:68)
    ... 4 more

After fixing file permissions via openhabian-config (menu 14) it worked again.

[ecdye]

What version of Java are you using? @mstormi we may need to make sure that permission corrections run after each openHAB upgrade.

[matmai]

openjdk version "1.8.0_252" OpenJDK Runtime Environment (Zulu 8.46.0.225-CA-linux_aarch32hf) (build 1.8.0_252-b225) OpenJDK Client VM (Zulu 8.46.0.225-CA-linux_aarch32hf) (build 25.252-b225, mixed mode, Evaluation)

[mstormi]

That's the OH cache. It is removed when you upgrade the openhab2 package. If that now exists with wrong permissions that's not because of openHABian. You have possibly manually started openHAB ?

@ecdye it doesn't hurt to run permissions_corrections() after any upgrade but I wouldn't know how we could have caused that

[matmai]

During the update process the log says that OH was not running:

...
run-parts: executing /etc/kernel/postinst.d/unattended-upgrades 4.19.118-v8+ /boot/kernel8.img
openhab2 (2.5.6-2) wird eingerichtet ...

[openHAB] openHAB was not running so will not start after upgrade.
[openHAB] Please use the command:
            sudo /bin/systemctl start openhab2.service

ca-certificates (20200601~deb10u1) wird eingerichtet ...
...

If I understand you right starting OH with openhab-cli start could have caused the problem?

Seems that could be the case because it could not acquire the lock:

$ sudo systemctl status openhab2.service
● openhab2.service - openHAB 2 - empowering the smart home
   Loaded: loaded (/usr/lib/systemd/system/openhab2.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Sun 2020-06-28 12:02:27 CEST; 4min 2s ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
 Main PID: 19791 (code=exited, status=0/SUCCESS)

Jun 28 12:02:19 openhab karaf[19791]:         at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule.asyncStop(EquinoxBundle.java:156)
Jun 28 12:02:19 openhab karaf[19791]:         at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle.stop(EquinoxBundle.java:262)
Jun 28 12:02:19 openhab karaf[19791]:         at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle.stop(EquinoxBundle.java:267)
Jun 28 12:02:19 openhab karaf[19791]:         at org.eclipse.osgi.launch.Equinox.stop(Equinox.java:123)
Jun 28 12:02:19 openhab karaf[19791]:         at org.apache.karaf.main.Main$2.run(Main.java:354)
Jun 28 12:02:19 openhab karaf[19791]: Caused by: java.util.concurrent.TimeoutException: Timeout after waiting 5 seconds to acquire the lock.
Jun 28 12:02:19 openhab karaf[19791]:         at org.eclipse.osgi.container.Module.lockStateChange(Module.java:334)
Jun 28 12:02:19 openhab karaf[19791]:         ... 5 more
Jun 28 12:02:27 openhab systemd[1]: openhab2.service: Succeeded.
Jun 28 12:02:27 openhab systemd[1]: Stopped openHAB 2 - empowering the smart home.

[mstormi]

If I understand you right starting OH with openhab-cli start could have caused the problem?

Yes. Did you do that? as root?

[matmai]

Yes, I executed sudo openhab-cli start. After all I think that is the root cause.

[mstormi]

Indeed, you must not do that. If you wanted to start OH, use systemctl start openhab2.

[BClark09]

I should add a "are you sure?" note to openhab-cli start

[matmai]

Thanks for clarifying this issue!