Upgrade to Openhab 2.1 fail to start

Hi, I been using Openhab for long now. And I must say I love it.
I run Openhab on Ubuntu and this week the system did an automatic upgrade to version 2.1. After that Openhab does not start any more.

● openhab2.service - openHAB 2 - empowering the smart home
Loaded: loaded (/usr/lib/systemd/system/openhab2.service; disabled; vendor preset: enabled)
Active: deactivating (stop) (Result: exit-code) since Tue 2017-07-11 11:27:15 CEST; 43ms ago
Docs: http://docs.openhab.org
https://community.openhab.org
Process: 17713 ExecStart=/usr/share/openhab2/start.sh server (code=exited, status=255)
Main PID: 17713 (code=exited, status=255); : 17911 (stop)
CGroup: /system.slice/openhab2.service
└─control
├─17911 /bin/sh /usr/share/openhab2/runtime/bin/stop
├─17931 /bin/sh /usr/share/openhab2/runtime/bin/stop
├─17932 /bin/sh /usr/share/openhab2/runtime/bin/stop
├─17933 /bin/sh /usr/share/openhab2/runtime/bin/stop
└─17936 /bin/sh /usr/share/openhab2/runtime/bin/stop

Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.storage.Storage.getChildStorageManager(Storage.java:1760)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.storage.Storage.getInfoInputStream(Storage.java:1777)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.storage.Storage.(Storage.java:128)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.storage.Storage.createStorage(Storage.java:87)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.internal.framework.EquinoxContainer.(EquinoxContainer.java:75)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.launch.Equinox.(Equinox.java:31)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFactory.java:24)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.apache.karaf.main.Main.launch(Main.java:253)
Jul 11 11:27:15 CASA-GB start.sh[17713]: at org.apache.karaf.main.Main.main(Main.java:177)
Jul 11 11:27:15 CASA-GB systemd[1]: openhab2.service: Main process exited, code=exited, status=255/n/a

I see on the log:

[SEVERE] [org.apache.karaf.main.Main] - Could not launch framework

Any help will be appreciated. I am a bit desperate. All my house is controled by openhab.

Thanks

ok.let’s try to check some stuff…
what is your java installation?

java -version

Also: Try to stop OH2, clear out /var/lib/openhab2/tmp/* & /var/lib/openhab2/cache/* and start again OH2 to see if this helps.

It may be that one of your rule files contains an error. It happened to me after the upgrade that OH didn’t start any more and it was due to errors in the rule file that apparently were there all the time - but OH did not bother.
In 2.1 it has a more strikt parser and refuses to launch.
Have a look at the log file and it may reveal this.

Thanks Brend. I removed all rules and I get the same problem.

java version "1.8.0_131"
Java™ SE Runtime Environment (build 1.8.0_131-b11)
Java HotSpot™ Server VM (build 25.131-b11, mixed mode)

/var/lib/openhab2/tmp/* it is empty
/var/lib/openhab2/cache/* does not exist

Thanks Angelos for your help

I don’t know what could be going wrong…
try /usr/share/openhab2/start_debug.sh to see if there are more useful info posted in the openhab.log

I get this:

Launching the openHAB runtime…
Listening for transport dt_socket at address: 5005
WARN: can’t update etc/config.properties with the generated command shutdown. We advise to manually add the karaf.shutdown.command property.
!SESSION 2017-07-11 18:59:58.250 -----------------------------------------------
eclipse.buildId=unknown
java.version=1.8.0_131
java.vendor=Oracle Corporation
BootLoader constants: OS=linux, ARCH=x86, WS=gtk, NL=es_ES

!ENTRY org.eclipse.osgi 4 0 2017-07-11 18:59:58.251
!MESSAGE Error reading configuration: Unable to create lock manager.
!STACK 0
java.io.IOException: Unable to create lock manager.
at org.eclipse.osgi.storagemanager.StorageManager.open(StorageManager.java:698)
at org.eclipse.osgi.storage.Storage.getChildStorageManager(Storage.java:1760)
at org.eclipse.osgi.storage.Storage.getInfoInputStream(Storage.java:1777)
at org.eclipse.osgi.storage.Storage.(Storage.java:128)
at org.eclipse.osgi.storage.Storage.createStorage(Storage.java:87)
at org.eclipse.osgi.internal.framework.EquinoxContainer.(EquinoxContainer.java:75)
at org.eclipse.osgi.launch.Equinox.(Equinox.java:31)
at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFactory.java:24)
at org.apache.karaf.main.Main.launch(Main.java:253)
at org.apache.karaf.main.Main.main(Main.java:177)

permissions (maybe?)

That sounds as if openHAB has lost permissions to access it’s folders, if you’re running apt, then the user:group config should be set to openhab:openhab, does a sudo chown -R openhab:openhab [dir] on each of openHAB’s directories solve the problem? i.e.

sudo chown -R openhab:openhab /var/lib/openhab2
sudo chown -R openhab:openhab /usr/share/openhab2
sudo chown -R openhab:openhab /var/log/openhab2
sudo chown -R openhab:openhab /etc/openhab2

@Dim beat me to the same point :wink:

1 Like
It did not work. Now I get:

Jul 12 00:14:57 CASA-GB systemd[1]: Started openHAB 2 - empowering the smart home.
Jul 12 00:14:57 CASA-GB start.sh[28742: Launching the openHAB runtime…
Jul 12 00:14:58 CASA-GB start.sh[28742: WARN: can’t update etc/config.properties with the generated command shutdown. We advise to manually add the karaf.shutdown.command property.
Jul 12 00:14:58 CASA-GB start.sh[28742: Unable to update instance pid: /usr/share/openhab2/runtime/instances/instance.properties (Permiso denegado)
Jul 12 00:14:58 CASA-GB start.sh[28742: /var/log/openhab2/openhab.log (Permiso denegado)
Jul 12 00:14:58 CASA-GB start.sh[28742: Unable to update instance pid: /usr/share/openhab2/runtime/instances/instance.properties (Permiso denegado)
Jul 12 00:14:58 CASA-GB systemd[1]: openhab2.service: Main process exited, code=exited, status=255/n/a
Jul 12 00:14:59 CASA-GB stop[28925]: stop: Ignoring predefined value for KARAF_HOME

I’m completely baffled, as far as you know this is a standard install of openHAB? I’ve not seen this before. I’d suggest making a backup of the /var/lib/openhab2, and /etc/openhab2 at this point just in case we need to do a purge and reinstall.

Would you be able to post the response of these commands?

ls -al /var/log/openhab2 /usr/share/openhab2/bin /var/lib/openhab2
cat /etc/default/openhab2
cat /usr/lib/systemd/system/openhab2.service

ls -al /var/log/openhab2 /usr/share/openhab2/bin /var/lib/openhab2
/usr/share/openhab2/bin:
total 8
drwxr-xr-x 2 777 openhab 4096 jul 11 10:48 .
drwxr-xr-x 5 777 openhab 4096 jul 11 10:48 …
-rwxrwxr-x 1 777 openhab 0 jun 28 01:13 setpermissions.sh

/var/lib/openhab2:
total 60
drwxr-xr-x 12 777 openhab 4096 jul 11 10:48 .
drwxr-xr-x 83 root root 4096 may 10 22:35 …
drwxrwxr-x 6 777 openhab 4096 may 28 10:47 config
drwxr-xr-x 2 777 openhab 12288 jul 11 10:48 etc
drwxrwxr-x 3 777 openhab 4096 jun 27 21:19 jsondb
drwxrwxr-x 3 777 openhab 4096 feb 1 13:12 kar
drwxrwxr-x 2 777 openhab 4096 feb 2 21:55 log
drwxrwxr-x 2 777 openhab 4096 feb 1 17:10 openhabcloud
drwxrwxr-x 2 777 openhab 4096 feb 1 13:12 .oracle_jre_usage
drwxr-xr-x 5 777 openhab 4096 feb 1 13:09 persistence
drwxr-xr-x 2 777 openhab 4096 jul 11 10:48 tmp
-rw-rw-r-- 1 777 openhab 36 feb 1 17:10 uuid
drwxrwxr-x 2 777 openhab 4096 jun 18 23:49 zwave

/var/log/openhab2:
total 84992
drwxr-xr-x 2 777 openhab 4096 jul 11 10:48 .
drwxrwxr-x 21 root syslog 4096 jul 12 07:36 …
-rwxr-xr-x 1 777 openhab 4299356 jul 9 23:46 events.log
-rwxr-xr-x 1 777 openhab 82679514 jul 12 00:02 openhab.log
-rwxr-xr-x 1 777 openhab 0 jun 28 01:13 Readme.txt

cat /etc/default/openhab2

openHAB 2 service configuration

Additional options for the JAVA_OPTS environment variable.

These will be appended to the execution of the openHAB Java runtime in front of all other options.

A couple of independent examples:

EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyAMA0"

EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"

EXTRA_JAVA_OPTS="-Djna.library.path=/lib/arm-linux-gnueabihf/ -Duser.timezone=Europe/Berlin -Dgnu.io.rxtx.SerialPorts=/dev/ttyS0"

EXTRA_JAVA_OPTS=""

The ports openHAB will bind its HTTP/HTTPS web server to.

#OPENHAB_HTTP_PORT=8080
#OPENHAB_HTTPS_PORT=8443

cat /usr/lib/systemd/system/openhab2.service
[Unit]
Description=openHAB 2 - empowering the smart home
Documentation=http://docs.openhab.org
Documentation=https://community.openhab.org
Wants=network-online.target
After=network-online.target

[Service]
EnvironmentFile=/etc/default/openhab2
User=casa
Group=root
WorkingDirectory=/usr/share/openhab2
#PermissionsStartOnly=true
#ExecStartPre=/usr/share/openhab/bin/setpermissions.sh
ExecStart=/usr/share/openhab2/start.sh server
ExecStop=/usr/share/openhab2/runtime/bin/stop

Shutdown delay in seconds, before process is tried to be killed with KILL (if configured)

TimeoutStopSec=120
Restart=on-failure

[Install]
WantedBy=multi-user.target

Thanks again.

Those are the results.
Sorry for the type of font. I don’t know why shows like that.

Found the problem! Is there any reason why you’ve changed these settings? This by default is

User=openhab
Group=openhab

No problem, you can wrap things in ticks to format them as if they were code

Like This

1 Like

I change the user long time ago, because I was getting all the time a permission problem.

I change it back to openhab, but I get this:

‘’‘
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.storage.Storage.getChildStorageManager(Storage.java:1760)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.storage.Storage.getInfoInputStream(Storage.java:1777)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.storage.Storage.(Storage.java:128)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.storage.Storage.createStorage(Storage.java:87)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.internal.framework.EquinoxContainer.(EquinoxContainer.java:75)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.launch.Equinox.(Equinox.java:31)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFactory.java:24)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.apache.karaf.main.Main.launch(Main.java:253)
Jul 12 15:16:14 CASA-GB start.sh[371]: at org.apache.karaf.main.Main.main(Main.java:177)
Jul 12 15:16:14 CASA-GB systemd[1]: openhab2.service: Main process exited, code=exited, status=255/n/a
’’’

To be clear, you changed both the user and group to openhab?

If you restart the machine, wait a few minutes and then post the output of:

sudo systemctl daemon-reload
sudo systemctl restart openhab2
sudo journalctl -u openhab2 -b

Yes I change both.

I run the commands and I get

‘’’
– Logs begin at mié 2017-07-12 15:43:07 CEST, end at mié 2017-07-12 15:45:13 CEST. –
jul 12 15:45:02 CASA-GB systemd[1]: Stopped openHAB 2 - empowering the smart home.
jul 12 15:45:02 CASA-GB systemd[1]: Started openHAB 2 - empowering the smart home.
jul 12 15:45:02 CASA-GB start.sh[3462]: Launching the openHAB runtime…
jul 12 15:45:06 CASA-GB start.sh[3462]: WARN: can’t update etc/config.properties with the generated command shutdo
jul 12 15:45:08 CASA-GB start.sh[3462]: !SESSION 2017-07-12 15:45:08.638 -----------------------------------------
jul 12 15:45:08 CASA-GB start.sh[3462]: eclipse.buildId=unknown
jul 12 15:45:08 CASA-GB start.sh[3462]: java.version=1.8.0_131
jul 12 15:45:08 CASA-GB start.sh[3462]: java.vendor=Oracle Corporation
jul 12 15:45:08 CASA-GB start.sh[3462]: BootLoader constants: OS=linux, ARCH=x86, WS=gtk, NL=es_ES
jul 12 15:45:08 CASA-GB start.sh[3462]: !ENTRY org.eclipse.osgi 4 0 2017-07-12 15:45:08.639
jul 12 15:45:08 CASA-GB start.sh[3462]: !MESSAGE Error reading configuration: Unable to create lock manager.
jul 12 15:45:08 CASA-GB start.sh[3462]: !STACK 0
jul 12 15:45:08 CASA-GB start.sh[3462]: java.io.IOException: Unable to create lock manager.
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.storagemanager.StorageManager.open(StorageMana
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.storage.Storage.getChildStorageManager(Storage
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.storage.Storage.getInfoInputStream(Storage.jav
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.storage.Storage.(Storage.java:128)
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.storage.Storage.createStorage(Storage.java:87)
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.internal.framework.EquinoxContainer.(Equ
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.launch.Equinox.(Equinox.java:31)
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFact
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.apache.karaf.main.Main.launch(Main.java:253)
jul 12 15:45:08 CASA-GB start.sh[3462]: at org.apache.karaf.main.Main.main(Main.java:177)
jul 12 15:45:08 CASA-GB systemd[1]: openhab2.service: Main process exited, code=exited, status=255/n/a
jul 12 15:45:09 CASA-GB stop[3656]: stop: Ignoring predefined value for KARAF_HOME
jul 12 15:45:11 CASA-GB stop[3656]: /var/lib/openhab2/tmp/port shutdown port file doesn’t exist. The container is
jul 12 15:45:11 CASA-GB systemd[1]: openhab2.service: Control process exited, code=exited status=3
’’’