[SOLVED] OH2.3 Fails to Start

Setup, Configuration and Use Beginners
1

I currently have OH2.0 running on an Ubuntu 14.4 VM. I’ve been a user since OH1.8, and have been using 2.0 for a couple years so this isn’t my first rodeo. However, I still consider myself a beginner, especially on the Linux end of things (it and I seem to have a hate-hate relationship). I have a few quirky issues and was looking to finally upgrade to 2.3 and upgrade Ubuntu at the same time.

Instead of upgrading my existing system, I’ve created a new VM and have 18.4 installed and running. Have Oracle Java 1.8.0_181-b13 installed and successfully registered (shows using java -version). I want to get this new VM up and running well and then I’ll make the switch from the old to new for daily use.

Installed OH2.3 and copied over all the configurations from my other system to this one as per:
Backing/Restoring up openHAB2.x

I’m sure I got my cart ahead of the horse partly there, but I don’t think it’s my current issue. I may be wrong… If I need to, I can blow this out and revert to default if need be (going to be my next step unless someone has any other bright ideas).

When I start the OH2 service and then run ‘systemctl status openhab2.service’, I get:

● 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 Sat 2018-09-22 23:34:56 CDT; 1s ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
  Process: 2725 ExecStart=/usr/share/openhab2/runtime/bin/karaf $OPENHAB_STARTMODE (code=exited, status=255)
 Main PID: 2725 (code=exited, status=255)

Sep 22 23:34:56 Server-Linux18 systemd[1]: openhab2.service: Main process exited, code=exited, status=255/n/a
Sep 22 23:34:56 Server-Linux18 systemd[1]: openhab2.service: Failed with result 'exit-code'.

Went to /usr/share/openhab2 and ran ‘bash start_debug.sh’ and I got:

Launching the openHAB runtime...
Listening for transport dt_socket at address: 5005
Unable to update instance pid: /var/lib/openhab2/tmp/instances/instance.properties (Permission denied)
java.lang.RuntimeException: /var/log/openhab2/openhab.log (Permission denied)
        at org.apache.karaf.main.util.BootstrapLogManager.getDefaultHandlerInternal(BootstrapLogManager.java:102)
        at org.apache.karaf.main.util.BootstrapLogManager.getDefaultHandlersInternal(BootstrapLogManager.java:137)
        at org.apache.karaf.main.util.BootstrapLogManager.getDefaultHandlers(BootstrapLogManager.java:70)
        at org.apache.karaf.main.util.BootstrapLogManager.configureLogger(BootstrapLogManager.java:75)
        at org.apache.karaf.main.Main.launch(Main.java:244)
        at org.apache.karaf.main.Main.main(Main.java:179)
Caused by: java.io.FileNotFoundException: /var/log/openhab2/openhab.log (Permission denied)
        at java.io.FileOutputStream.open0(Native Method)
        at java.io.FileOutputStream.open(FileOutputStream.java:270)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
        at org.apache.karaf.main.util.BootstrapLogManager$SimpleFileHandler.open(BootstrapLogManager.java:193)
        at org.apache.karaf.main.util.BootstrapLogManager$SimpleFileHandler.<init>(BootstrapLogManager.java:182)
        at org.apache.karaf.main.util.BootstrapLogManager.getDefaultHandlerInternal(BootstrapLogManager.java:100)
        ... 5 more
!SESSION 2018-09-22 23:35:22.990 -----------------------------------------------
eclipse.buildId=unknown
java.version=1.8.0_181
java.vendor=Oracle Corporation
BootLoader constants: OS=linux, ARCH=x86_64, WS=gtk, NL=en_US

!ENTRY org.eclipse.osgi 4 0 2018-09-22 23:35:22.990
!MESSAGE Error reading configuration: /var/lib/openhab2/cache/org.eclipse.osgi/.manager/.fileTableLock (Permission denied)
!STACK 0
java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.manager/.fileTableLock (Permission denied)
        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)
        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:179)

Looked in the openhab.log file and see this:

2018-09-22 22:34:09.852 [SEVERE] [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:179)
Caused by: java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.manager/.fileTableLock (Permission denied)
	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

At this point, I made sure that all the openhab config folders, etc. didn’t have any permission issues (chmod 777) and were owned by the default user (chown).

Then, when I ran ‘bash start_debug.sh’, I got:

Launching the openHAB runtime...
mkdir: cannot create directory ‘/usr/share/openhab2/userdata/tmp’: No such file or directory
KARAF_BASE is not valid: /usr/share/openhab2/userdata

Error changed and got smaller, so I’ll take that as progress…

There is no userdata folder. Looking at my OH2.0 system, it doesn’t have one either. As something to try, I create the userdata folder and make sure it has write access, etc. like I did everywhere else.

Still essentially the same thing from the service status:

● 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 Sat 2018-09-22 23:51:05 CDT; 3s ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
  Process: 3754 ExecStart=/usr/share/openhab2/runtime/bin/karaf $OPENHAB_STARTMODE (code=exited, status=255)
 Main PID: 3754 (code=exited, status=255)

Sep 22 23:51:05 Server-Linux18 systemd[1]: openhab2.service: Main process exited, code=exited, status=255/n/a
Sep 22 23:51:05 Server-Linux18 systemd[1]: openhab2.service: Failed with result 'exit-code'.

But my messag when running ‘bash start_debug.sh’, changed:

Launching the openHAB runtime...
KARAF_ETC is not valid: /usr/share/openhab2/userdata/etc

There is no etc file or directory within userdata. I verified the permissions on userdata to 777 and chowned it again to the default user with no change. Googling this, I haven’t found anyone that has had a KARAF_ETC issue. I guess I’m special… What mistifies me is that I don’t have this folder on my other system and it runs fine. Guessing it’s a change that’s been made between 2.0 and 2.3?

Here’s what I see in my openhab.log:

2018-09-22 23:51:11.753 [SEVERE] [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:179)
Caused by: java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.manager/.fileTableLock (Permission denied)
	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

This really doesn’t help me at all, but maybe it will mean more to someone else…

I’ve searched and tried everything I can think of with no effect. Ideas?

Thanks,

Danny

2

Well you could start debugging (I’d look at ALL permissions and ownership on directories all the way up to / for all those filenames it spits out it cannot access and compare them to your old working install).
But you cannot be sure you’ll find and fix everything that way, so a probably the better way is this:
Do you still have access to your working old OH ?
Use the openhab-cli script to backup its config (if it isn’t contained there, copy it over from your new install).
Also take extra backups (tar or whatever) of your new install, particularly of files you have changed since you moved.

Then reinstall OH: apt-get purge openhab2; apt-get install openhab2 plus again for the -addons and -addons-legacy packages in case you use them.

3

If using the debian package, calling the start.sh scripts directly won’t work. Try using:

openhab-cli start

What is the output of

openhab-cli info
4

Running ‘openhab-cli start’, I get this:

A systemd service configuration exists...
Use 'sudo /bin/systemctl start openhab2.service' to start an openHAB service
Launching an instance in this terminal..
Launching the openHAB runtime...
log4j:WARN No appenders could be found for logger (org.ops4j.pax.url.mvn).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

                          __  _____    ____
  ____  ____  ___  ____  / / / /   |  / __ )
 / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __  |
/ /_/ / /_/ /  __/ / / / __  / ___ |/ /_/ /
\____/ .___/\___/_/ /_/_/ /_/_/  |_/_____/
    /_/                        2.3.0
                               Release Build

Hit '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
Hit '<ctrl-d>' or type 'system:shutdown' or 'logout' to shutdown openHAB.

Error in initialization script: shell.init.script,scripts/*.script (No such file or directory)
openhab>

Running ‘openhab-cli info’, I get:

Version:     2.3.0 (Build)

User:        openhab (Environment Variable Set)
User Groups: openhab tty dialout audio

Directories: Folder Name      | Path                        | User:Group
             -----------      | ----                        | ----------
             OPENHAB_HOME     | /usr/share/openhab2         | danny:openhab
             OPENHAB_RUNTIME  | /usr/share/openhab2/runtime | danny:openhab
             OPENHAB_USERDATA | /var/lib/openhab2           | danny:openhab
             OPENHAB_CONF     | /etc/openhab2               | danny:openhab
             OPENHAB_LOGDIR   | /var/log/openhab2           | danny:openhab

URLs:        http://192.168.150.21:8080
             https://192.168.150.21:8443

Yeah, blowing out the install and re-installing was going to be my next thing to try so I guess I’ll do that now.

Thanks,

Danny

5

Blowing out the install and re-installing things has it running. All I can guess is that something in my 2.0 configs isn’t liked by 2.3. I think I’m going to manually reconfigure everything to be safe, and only move over rules, items, etc.

Thanks,

Danny

6

Your openHAB permissions are (were) wrong, instead of user danny it needs to be openhab.