Since the move, it does not work anymore. Can anyone give me a hint as to why? the configuration file is located unter /openhab/userdata/etc/log4j2.xml within the docker container, but it won’t send the JSON over. The file is exactly the same as before in my bare metal installation. there’s no indication in the logs otherwise?
What’s your network settings for the container. Is it host or do you manually expose the ports?
There might be hints as to the problem in the stdout logs that happen before OH starts logging to the files. You can see those using docker logs openhab. docker logs -f openhab will follow those logs as they are written. You mat want to pipe that to less because it’s going to dump all the logs.
I assume you’ve mounted a volume for userdata?
From inside the container can out ping the IP or hostname you’ve used in the log4j2.xml config for where to send the logs to ELK?
Thanks Rich for your help.
and yes, I had to re-install log4j2 Extra AFAIR after the migration, the openHAB container runs in host-mode. docker logs openhab show the console logs until “launching the openHAB runtime…”. The event.log/openhab.log stored at /openhab/userdata/logs are fine and yes, those are in a volume.
Inside the container I can easily ping the IP and hostname of the logstash container. That’s why I’m puzzled as to where else to look.
oh, and from within the container I could reach logstash:
root@openhabmain:/openhab# nc -zv 192.168.78.20 5000
Connection to 192.168.78.20 5000 port [tcp/*] succeeded!
And the results of docker log openhabmain? We are particularly interested in any errors that may be logged out to stdout during startup. It won’t log out logger based errors to a file. Why would it if it knows the logger isn’t working?
+ IFS='
'
++ find /usr/lib/jvm -mindepth 1 -maxdepth 1 -type d
+ export JAVA_HOME=/usr/lib/jvm/java-17-openjdk-amd64
+ JAVA_HOME=/usr/lib/jvm/java-17-openjdk-amd64
+ '[' unlimited = unlimited ']'
+ echo 'Configuring Java unlimited strength cryptography policy...'
+ sed -i 's/^crypto.policy=limited/crypto.policy=unlimited/' /usr/lib/jvm/java-17-openjdk-amd64/conf/security/java.security
Configuring Java unlimited strength cryptography policy...
+ 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'
+ id -u openhab
Starting with openhab user id: 9001 and group id: 9001
++ getent group 9001
Create group openhab with id 9001
+ '[' -z '' ']'
+ echo 'Create group openhab with id 9001'
+ groupadd -g 9001 openhab
Create user openhab with id 9001
+ echo 'Create user openhab with id 9001'
+ adduser -u 9001 --disabled-password --gecos '' --home /openhab --gid 9001 openhab
adduser: Warning: The home dir /openhab you specified already exists.
Adding user `openhab' ...
Adding new user `openhab' (9001) with group `openhab (9001)' ...
adduser: The home directory `/openhab' already exists. Not touching this directory.
adduser: Warning: The home directory `/openhab' does not belong to the user you are currently creating.
Adding new user `openhab' to supplemental / extra groups `users' ...
Adding user `openhab' to group `users' ...
+ 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' ...
Done.
+ adduser openhab audio2
Adding user `openhab' to group `audio2' ...
Done.
+ adduser openhab audio3
Adding user `openhab' to group `audio3' ...
Done.
+ adduser openhab audio4
Adding user `openhab' to group `audio4' ...
Done.
+ adduser openhab audio5
Adding user `openhab' to group `audio5' ...
Done.
+ adduser openhab dialout
Adding user `openhab' to group `dialout' ...
Done.
+ adduser openhab dialout2
Adding user `openhab' to group `dialout2' ...
Done.
+ adduser openhab dialout3
Adding user `openhab' to group `dialout3' ...
Done.
+ adduser openhab dialout4
Adding user `openhab' to group `dialout4' ...
Done.
+ adduser openhab gpio
Adding user `openhab' to group `gpio' ...
Done.
+ adduser openhab uucp
Adding user `openhab' to group `uucp' ...
Done.
+ adduser openhab uucp2
Adding user `openhab' to group `uucp2' ...
Done.
+ adduser openhab 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
misc
persistence
rules
scripts
services
sitemaps
sounds
tags
things
transform' ']'
+ initialize_volume /openhab/userdata /openhab/dist/userdata
+ volume=/openhab/userdata
+ source=/openhab/dist/userdata
++ ls -A /openhab/userdata
+ '[' -z 'cache
config
etc
ipcamera
jsondb
logs
marketplace
openhabcloud
persistence
schema_check.txt
secrets
tmp
uuid' ']'
++ 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...
This was the penultimate start, which went as far as I can see smoothly.
the last start was not so smooth, that one I did was this morning as I tried if changing the /openhab/dist/userdata/etc/log4j2.xml had any effect (which it didn’t).
this start took surprisingly long and a quick check at the logs in portainer didn’t come up with something suspicous. Just as you just wrote that I cam across this:
...
This command is not for general use and should only be run as the result of a call to
ProcessBuilder.start() or Runtime.exec() in a java application
Incorrect Java version: 17.0.14+7-Debian-1deb12u1
jspawnhelper version 17.0.15+6-Debian-1deb12u1
This command is not for general use and should only be run as the result of a call to
ProcessBuilder.start() or Runtime.exec() in a java application
Incorrect Java version: 17.0.14+7-Debian-1deb12u1
jspawnhelper version 17.0.15+6-Debian-1deb12u1
This command is not for general use and should only be run as the result of a call to
ProcessBuilder.start() or Runtime.exec() in a java application
Incorrect Java version: 17.0.14+7-Debian-1deb12u1
jspawnhelper version 17.0.15+6-Debian-1deb12u1
This command is not for general use and should only be run as the result of a call to
ProcessBuilder.start() or Runtime.exec() in a java application
Incorrect Java version: 17.0.14+7-Debian-1deb12u1
jspawnhelper version 17.0.15+6-Debian-1deb12u1
This command is not for general use and should only be run as the result of a call to
ProcessBuilder.start() or Runtime.exec() in a java application
+ IFS='
'
++ find /usr/lib/jvm -mindepth 1 -maxdepth 1 -type d
+ export JAVA_HOME=/usr/lib/jvm/java-17-openjdk-amd64
+ JAVA_HOME=/usr/lib/jvm/java-17-openjdk-amd64
+ '[' unlimited = unlimited ']'
+ echo 'Configuring Java unlimited strength cryptography policy...'
Configuring Java unlimited strength cryptography policy...
+ sed -i 's/^crypto.policy=limited/crypto.policy=unlimited/' /usr/lib/jvm/java-17-openjdk-amd64/conf/security/java.security
+ capsh --print
+ grep -E Current:.+,cap_net_admin,cap_net_raw,.+
+ rm -f '/var/lock/LCK..*'
+ rm -f /openhab/userdata/tmp/instances/instance.properties
Starting with openhab user id: 9001 and group id: 9001
+ NEW_USER_ID=9001
+ NEW_GROUP_ID=9001
+ echo 'Starting with openhab user id: 9001 and group id: 9001'
+ id -u openhab
+ initialize_volume /openhab/conf /openhab/dist/conf
+ volume=/openhab/conf
+ source=/openhab/dist/conf
++ ls -A /openhab/conf
+ '[' -z 'automation
html
icons
items
misc
persistence
rules
scripts
services
sitemaps
sounds
tags
things
transform' ']'
+ initialize_volume /openhab/userdata /openhab/dist/userdata
+ volume=/openhab/userdata
+ source=/openhab/dist/userdata
++ ls -A /openhab/userdata
+ '[' -z 'cache
config
etc
ipcamera
jsondb
logs
marketplace
openhabcloud
persistence
schema_check.txt
secrets
tmp
uuid' ']'
++ 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...
I had to do a apt update, apt upgrade and apt install nano, because I needed to change that log4j2.xml… there’s now nearly 8500 lines of the incorrect Java version as a result of this - but openHAB in docker is stable and doesn’t use significant more performance…
It wouldn’t. Those are the default files that OH shops with and they are only used when the entrypoint script notices that your version of OH, based on what’s in /openhab/userdata/etc/versions.properties, is different from the version in the image. Then it copies the userdata/etc folder over as part of the upgrade process.
You should not edit those files.
That may point to OH thinking it had to do an upgrade which means it cleared the cache and did some other steps. Do you see anything in userdata/logs/update.log? That shows what entrypoint did during an upgrade of the configs because there’s a new version of OH. It also takes a backup automatically, putting it under userdata/backup. So it’s always possible to go back if you need to.
That’s not going to work if you were running OH 4 and ended up upgrading to OH 5. OH 5 requires a different version of Java.
And you shouldn’t need to be installing anything in the container to edit a config file. That’s one of the points of volumes. You should be able to edit those files from the host.
For example, I have /srv/openhab/userdata on my host mounted as a volume into the container to /openhab/userdata. I edit the files on my host by opening the files in /srv/openhab/userdata and openHAB sees it because it sees the same files under /openhab/userdata.
If you are using Docker volumes instead of mounting a local host folder into the container, you’d edit the files from /var/lib/docker/volumes/<name of volume>.
You do not edit the config files inside the container itself.
Thanks for the help, Rich! Appreciated. normally I wouldn’t change anything within the container of course, but I tried to see, if any log4j2.xml had any effect on anything. and to make it “easier” for me I had to apt update to install nano. FWIW, I had 4.3.5 after my “incident”.
I reverted to stock-container just now and of course edited the /openhab/userdata/etc/log4j2.xml in my volume “outside” of the container.
but back to topic: You also don’t see anything suspicious with the startup of openHAB?
the contents of /openhab/userdata/logs/update.log:
Image and userdata versions differ! Starting an upgrade.
You can find backup of userdata in /openhab/userdata/backup/userdata-2023-01-10T15-56-14.tar
################################################
openHAB Docker update script
################################################
The script will attempt to update openHAB to version 3.4.1
Please read the following e[32mnotese[m and e[31mwarningse[m:
Important notes for version 3.4.0:
e[31mWarning:e[m CORE: Default units have been added for all dimensions. A state description defining the unit should be added to each item that uses a different unit.
e[31mWarning:e[m Automower Binding: Due to Husqvarna Authentication API change, bridge now requires application secret instead of username and password. Delete any existing bridge and re-add it, please make sure to update all automower things to use the newly added bridge.
e[31mWarning:e[m JavaScript Scripting Automation: 'setTimeout' and 'setInterval' return a timerId (a positive integer value) as in standard JS instead of an openHAB Timer.
e[31mWarning:e[m JavaScript Scripting Automation: ItemHistory min/max between/since returns now a number instead of a string.
e[31mWarning:e[m JavaScript Scripting Automation: openHAB JavaScript library versions < 3.1.2 are not fully compatible anymore. If you have manually installed the JS library, please upgrade to a version >= 3.1.2.
e[31mWarning:e[m JRuby Scripting Automation: The default `RUBYLIB` directory has changed to OPENHAB_CONF/automation/ruby/lib. Either explicitly configure the add-on to use the previous value, or move any files to the new location.
e[31mWarning:e[m Konnected Binding: Things needs to be recreated because of added Konnected Pro panel support and manual configuration of things.
e[31mWarning:e[m LG webOS Binding: The undocumented action "sendRCButton" was removed while it is possible to achieve the same action with "sendButton"
e[31mWarning:e[m Miele@home Binding: The channel 'start' now contains date and time for start of scheduled program. Previously it was counting down duration until the program would start.
e[31mWarning:e[m Miele@home Binding: The channels 'duration', 'elapsed' and 'finish' are now Number:Time. You may need to remove and create your things again in case your things were previously created using UI and you want to use these channels. Linked items need to be recreated.
e[31mWarning:e[m Resol Binding: Item Type of solar controllers channels using time and weekday format changed from Date to String. Items need to be adjusted accordingly.
e[31mWarning:e[m Systeminfo Binding: Multiple Number channels now have a dimension added. You may need to remove and create your things again in case your things were previously created using UI and you want to use these channels. Linked items need to be recreated.
e[31mWarning:e[m Systeminfo Binding: The default state description for DataAmount channels is now MiB. If you relied on MB, you may need to adjust.
e[31mWarning:e[m Velux Binding: On window things the semantic category of the position channel has been corrected from 'blinds' to 'window'. Window things with such channels that had been created via the UI will need to be deleted and re-created.
e[31mWarning:e[m Xiaomi Wifi devices (Mi IO) Binding: Channel Type change for some yeelights. The brightness channels with the Number type now have the Dimmer type. This affects only nightlight and ambilight channels for some models.
Replacing userdata system files with newer versions...
Clearing cache...
Performing post-update tasks for version 3.4.0:
SUCCESS: openHAB updated from 3.3.0 to 3.4.1
=> this seems to be an very old entry as I updatedd my then 3.3.0 to 3.4.1 on Raspberry Pi back then…, which since made it via backup into my docker. Surprisingly no entries for upgrading from 3.4.1 until 4.3.5, which I also did on my pi-install.
I didn’t see anything to indicate that the logger is failing to connect or anything related to that. The “ProcessBuilder.start()” logs are weird and the incorrect Java version are concerning but nothing seems related to the loggers.
You can always see if changes to the log4j2.xml file are being picked up by changing the logging level to something chatty. for example, change the ItemStateUpdatedEvent to INFO. If you start to see every Item update, even if the Item doesn’t change, in events.log then you’ll know the changes to the file are being picked up.
I don’t know when/how that log file gets created. I thought it was specific to just the Docker instance of OH but maybe other types of installs create it too. I’ve been running in Docker since the official Docker image was released many years ago.
But that does confirm either the container didn’t have permission to edit that file, or it in fact did not go through an upgrade when you edited the files in the dist folder.
So I just dug a bit deeper into the matter and it seems somehow my logstash didn’t accept openhab.logs anymore. I didn’t realize, because the log was so big it didn’t load via portainer and my other logs like from my mosquitto-server did come through.
So I fixed that with a logstash restart and now it works again. Sorry Rich, was my own fault, had nothing to do with openHAB, the log4j2.xml did work as intended…
