Log file has errors - causes/how important are they?

Agent_Smith · June 25, 2025, 10:03pm

Platform information:
- Hardware: x86 32 bit
- OS: Ubuntu server LTS 18.4
- Java Runtime Environment: 17
- openHAB version:4.3
  I looked at the output of log:tail and saw the following

17:25:46.608 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'DeckPlantsWaterValve_Power' changed from OFF to ON
17:26:46.646 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'DeckPlantsWaterValve_Power' changed from ON to OFF
17:27:16.871 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'DeckPlantsWaterValve_Power' changed from OFF to ON
17:28:16.936 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'DeckPlantsWaterValve_Power' changed from ON to OFF
17:45:21.938 [Karaf ssh console user openhab] ERROR org.apache.karaf.shell.support.ShellUtil - Exception caught while executing command
java.lang.IllegalStateException: Unrecognized configuration
        at org.apache.karaf.log.core.internal.LogServiceImpl.getDelegate(LogServiceImpl.java:71) ~[?:?]
        at org.apache.karaf.log.core.internal.LogServiceImpl.getLevel(LogServiceImpl.java:89) ~[?:?]
        at org.apache.karaf.log.command.LogTail$LogServiceTracker.addingService(LogTail.java:94) ~[?:?]
        at org.apache.karaf.log.command.LogTail$LogServiceTracker.addingService(LogTail.java:76) ~[?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:943) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:871) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:321) ~[osgi.core-8.0.0.jar:?]
        at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:264) ~[osgi.core-8.0.0.jar:?]
        at org.apache.karaf.log.command.LogTail.execute(LogTail.java:54) ~[?:?]
        at org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:88) ~[?:?]
        at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) ~[?:?]
        at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) ~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
Error executing command: Unrecognized configuration

What is causing the errors and what to do to correct it?

Also, it is my understanding that log:tail Continuously displays log entries, as in monitoring the log file and outputting any changes to the console in real time…it does not seem to be doing that…
Thoughts? Help?

pacive · June 26, 2025, 4:51am

Never seen this error, but it seems like the logging configuration has some error. Have you done any modification to the log4j2.xml file?

Agent_Smith · June 26, 2025, 2:28pm

havent touched log4j2.xml file.
I initially had JRE 22 installed and deinstalled/removed it because openhab 4 specified JRE 17. Maybe there is something ‘left over’ that is causing the issue.

Need to investigate further but I have a hate-hate relationship with Java and JRE. Without exception, any tool or environment that I touched/developed/worked in built on Java always had problems. Way too complicated and brittle.

Agent_Smith · June 26, 2025, 8:00pm

I’ve continued to try various commands in the openhab karaf console, e.g. log:clear, log:tail, log:display, etc..after each command action a Java illegalStateException is thrown…

java.lang.IllegalStateException: Unrecognized configuration
        at org.apache.karaf.log.core.internal.LogServiceImpl.getDelegate(LogServiceImpl.java:71) ~[?:?]
        at org.apache.karaf.log.core.internal.LogServiceImpl.getLevel(LogServiceImpl.java:89) ~[?:?]
        at org.apache.karaf.log.command.GetLogLevel.execute(GetLogLevel.java:49) ~[?:?]
        at org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:88) ~[?:?]
        at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) ~[?:?]
        at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) ~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
Error executing command: Unrecognized configuration
openhab>

Can anyone shed some light on what could be causing this and how to fix it?
It is annoying because when I want to monitor commands & actions in real time, I get the error dump and monitoring ceases, and I am back at the prompt.

Is there another way to monitor actions? (as a work around to this?)
Thanks

sihui · June 26, 2025, 8:22pm

If I were you I would get the default files and overwrite yours:

github.com/openhab/openhab-distro

distributions/openhab/src/main/resources/userdata/etc/org.ops4j.pax.logging.cfg

main

org.ops4j.pax.logging.log4j2.config.file=${karaf.etc}/log4j2.xml

github.com/openhab/openhab-distro

distributions/openhab/src/main/resources/userdata/etc/log4j2.xml

main

<?xml version="1.0" encoding="UTF-8" standalone="no"?><Configuration monitorInterval="10">

	<Appenders>
		<!-- Console appender not used by default (see Root logger AppenderRefs) -->
		<Console name="STDOUT">
			<PatternLayout pattern="%d{HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
		</Console>

		<!-- Rolling file appender -->
		<RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/openhab.log.%i.gz" name="LOGFILE">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
			<Policies>
				<OnStartupTriggeringPolicy/>
				<SizeBasedTriggeringPolicy size="16 MB"/>
			</Policies>
			<DefaultRolloverStrategy max="7"/>
		</RollingFile>

		<!-- Event log appender -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i.gz" name="EVENT">

This file has been truncated. show original

wborn · June 26, 2025, 8:33pm

Yes try what @sihui suggests.

According to the Karaf code it cannot find any logging config so it throws the exception:

github.com/apache/karaf

log/src/main/java/org/apache/karaf/log/core/internal/LogServiceImpl.java

a021c6b4c


      
              }
              else if (config.get("org.ops4j.pax.logging.logback.config.file") != null) {
                  String file = config.get("org.ops4j.pax.logging.logback.config.file").toString();
                  if (file.endsWith(".xml")) {
                      return new LogServiceLogbackXmlImpl(file);
                  } else {
                      throw new IllegalStateException("Unsupported Logback configuration type: " + file);
                  }
              }
              else {
                  throw new IllegalStateException("Unrecognized configuration");
              }
          }
          
          public String getLevel() {
              return getLevel(LogServiceInternal.ROOT_LOGGER).get(LogServiceInternal.ROOT_LOGGER);
          }
          
          public Map<String, String> getLevel(String logger) {
              Configuration cfg;
              try {

Agent_Smith · June 26, 2025, 10:42pm

thank you. for the uninitiated, would you please explain how to do this? is it purely manual process? e.g, download the files, delete the existing files in my openhab directories and copy the new files over?

pacive · June 27, 2025, 4:49am

That and possibly restarting OH after should be enough, yes.

Agent_Smith · June 27, 2025, 2:03pm

Since it can’t find any ‘logging configuration’ it raises the question:
Is the logging configuration pre-defined and part of the installation OR, is it something that needs to be configured before it can be effective?

I was reading some docs and one can configure what kinds of information can be displayed in the monitor output. I’d like to think that some predefined set of information is already contained in the monitor function.

I’ll go back and copy the suggested files into the existing installation.

sihui · June 27, 2025, 2:08pm

Yes

No

Agent_Smith · June 30, 2025, 3:02am

Need a little more help…
‘whereis’ tells me openhab is installed in /etc/openhab and /usr/share/openhab. Searching those directories for log4j2.xml and ops4j.pax.logging.cfg ‘find’ comes up empty.

what are the paths to the above files?

pacive · June 30, 2025, 4:53am

They are located in /var/lib/openhab/etc/.

ErikDB · June 30, 2025, 4:54am

See Logging | openHAB. They’re in /var/lib/openhab/etc.

Edit: seems I was late to the party

Agent_Smith · June 30, 2025, 11:57am

Thank you. I did find log4j2.xml in

/var/lib/openhab/etc/

however, org.ops4j.pax.logging.log4j2.config is nowhere to be found…

That may be the problem, so should I just copy the file from the distro in /var/lib/openhab/etc/ ?

sihui · June 30, 2025, 12:16pm

Yes.
But filename is

org.ops4j.pax.logging.cfg

Agent_Smith · June 30, 2025, 12:50pm

Thanks, and whoops, I fat fingered the file name…

Agent_Smith · June 30, 2025, 8:15pm

I copied to two files:

log4j2.xml 
org.ops4j.pax.logging.cfg

And had some success but…still get errors…

I go to my smart plugin socket via the model: Outdoors->Deck->PlantWaterValve-> Power and change the state from Off to On. The action occurs, then about 10 seconds later, I get error messages (and they repeat ~every 10 seconds):

16:10:51.384 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'DeckPlantsWaterValve_Power' received command ON
16:10:51.388 [INFO ] [openhab.event.ItemStatePredictedEvent] - Item 'DeckPlantsWaterValve_Power' predicted to become ON
16:10:51.410 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'DeckPlantsWaterValve_Power' changed from OFF to ON
16:11:00.165 [ERROR] [ry.mdns.internal.MDNSDiscoveryService] - Participant 'org.openhab.binding.ipp.internal.discovery.IppPrinterDiscoveryParticipant' threw an exception
java.lang.NullPointerException: null
        at java.util.Objects.requireNonNull(Objects.java:209) ~[?:?]
        at java.util.ImmutableCollections$MapN.<init>(ImmutableCollections.java:1186) ~[?:?]
        at java.util.Map.of(Map.java:1395) ~[?:?]
        at org.openhab.binding.ipp.internal.discovery.IppPrinterDiscoveryParticipant.createResult(IppPrinterDiscoveryParticipant.java:98) ~[?:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.createDiscoveryResult(MDNSDiscoveryService.java:222) [bundleFile:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.considerService(MDNSDiscoveryService.java:214) [bundleFile:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.serviceResolved(MDNSDiscoveryService.java:207) [bundleFile:?]
        at javax.jmdns.impl.ListenerStatus$ServiceListenerStatus.serviceResolved(ListenerStatus.java:106) [bundleFile:3.5.12]
        at javax.jmdns.impl.JmDNSImpl$1.run(JmDNSImpl.java:911) [bundleFile:3.5.12]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
16:11:00.178 [ERROR] [ry.mdns.internal.MDNSDiscoveryService] - Participant 'org.openhab.binding.ipp.internal.discovery.IppPrinterDiscoveryParticipant' threw an exception
java.lang.NullPointerException: null
        at java.util.Objects.requireNonNull(Objects.java:209) ~[?:?]
        at java.util.ImmutableCollections$MapN.<init>(ImmutableCollections.java:1186) ~[?:?]
        at java.util.Map.of(Map.java:1395) ~[?:?]
        at org.openhab.binding.ipp.internal.discovery.IppPrinterDiscoveryParticipant.createResult(IppPrinterDiscoveryParticipant.java:98) ~[?:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.createDiscoveryResult(MDNSDiscoveryService.java:222) [bundleFile:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.considerService(MDNSDiscoveryService.java:214) [bundleFile:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.serviceResolved(MDNSDiscoveryService.java:207) [bundleFile:?]
        at javax.jmdns.impl.ListenerStatus$ServiceListenerStatus.serviceResolved(ListenerStatus.java:106) [bundleFile:3.5.12]
        at javax.jmdns.impl.JmDNSImpl$1.run(JmDNSImpl.java:911) [bundleFile:3.5.12]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
16:11:00.183 [ERROR] [ry.mdns.internal.MDNSDiscoveryService] - Participant 'org.openhab.binding.ipp.internal.discovery.IppPrinterDiscoveryParticipant' threw an exception
java.lang.NullPointerException: null
        at java.util.Objects.requireNonNull(Objects.java:209) ~[?:?]
        at java.util.ImmutableCollections$MapN.<init>(ImmutableCollections.java:1186) ~[?:?]
        at java.util.Map.of(Map.java:1395) ~[?:?]
        at org.openhab.binding.ipp.internal.discovery.IppPrinterDiscoveryParticipant.createResult(IppPrinterDiscoveryParticipant.java:98) ~[?:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.createDiscoveryResult(MDNSDiscoveryService.java:222) [bundleFile:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.considerService(MDNSDiscoveryService.java:214) [bundleFile:?]
        at org.openhab.core.config.discovery.mdns.internal.MDNSDiscoveryService.serviceResolved(MDNSDiscoveryService.java:207) [bundleFile:?]
        at javax.jmdns.impl.ListenerStatus$ServiceListenerStatus.serviceResolved(ListenerStatus.java:106) [bundleFile:3.5.12]
        at javax.jmdns.impl.JmDNSImpl$1.run(JmDNSImpl.java:911) [bundleFile:3.5.12]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]

Sigh…what is it complaining about? how to fix?
I’ve been reading about how to tailor the output of the logger. I would like to see only INFO log entries but I don’t see how to specify that. Suggestions?

rlkoshak · June 30, 2025, 8:41pm

The error is coming from the IPP addon: IPP - Bindings | openHAB.

Is this add-on installed? I guess it must be. How did you install it, the usual way or some other way (e.g. downloaded a jar file and dropped it into the add-ons folder)? Do you use this add-on or plan to use the add-on?

Something is going wrong with the scan for new printers that you’ve not accepted from the inbox. The binding will scan for new devices periodically. The fact that it happened after toggling the socket is probably a coincidence.

I don’t use this add-on but just tried to install it can scan for devices and didn’t see any errors (OH 5.0 M3). But it also didn’t find either of my printers as I expected. But I didn’t see any errors. I’ll let it sit for a bit and see if it only throws errors when it automatically scans for new printers but if I don’t come back it means no errors.

If you don’t need/want to connect your printers to OH, you can remove the add-on and the errors will go away. If you do want these, there might be a bug in the add-on or something weird about your installation. The fact that your logging config files mysteriously disappeared does make your overall installation somewhat suspect. These files don’t normally just disappear.

Agent_Smith · June 30, 2025, 10:37pm

thank you for the insight. I did the install via a package installer for Ubuntu (18.04LTS). According to the openhab website it uses the apt pkg mgr and the version is 4.3.5 stable, 32bit architecture.
I opted for the UI driven configuration because I thought it would be relatively easy to get two plugs working on a scheduled basis (boy, was I wrong).

I seem to remember that during install it discovered a printer and I remember thinking Why does openhab need to access a printer as part of its devices? In order to keep the install happy (presumably) I think I accepted everything it found. After all, it found it so it should know how to configure/deal with the devices. Surprisingly, it did not discover the two Kasa smart plugs.

I don’t recall explicitly installing the addon. I just basically followed the prompts and accepted things.

Yes, agreed, since ```
org.ops4j.pax.logging.cfg

was not installed and is central to the logger operation, I was surprised....but I didn't do anything out of the ordinary for the install.  The only thing that was 'different' was that I had JVM v21 development environment installed and I removed it prior to reinstalling v17.   Maybe something was not removed completely (I hate java!).
I'll try and figure out how to remove the printer as I  do not need it.
Thanks

Agent_Smith · June 30, 2025, 10:54pm

another piece of information…when I log into openhab via the cli:

$OPENHAB_RUNTIME/bin/client

I get the following:

SLF4J(W): No SLF4J providers were found.
SLF4J(W): Defaulting to no-operation (NOP) logger implementation
SLF4J(W): See https://www.slf4j.org/codes.html#noProviders for further details.
SLF4J(W): Class path contains SLF4J bindings targeting slf4j-api versions 1.7.x or earlier.
SLF4J(W): Ignoring binding found at [jar:file:/usr/share/openhab/runtime/system/org/apache/karaf/org.apache.karaf.client/4.4.6/org.apache.karaf.client-4.4.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J(W): See https://www.slf4j.org/codes.html#ignoredBindings for an explanation.
Logging in as openhab
Password:
/var/lib/openhab/tmp/jansi-2.4.1-d51e434fae593b83-libjansi.so.lck (Permission denied)

                           _   _     _     ____
   ___   ___   ___   ___  | | | |   / \   | __ )
  / _ \ / _ \ / _ \ / _ \ | |_| |  / _ \  |  _ \
 | (_) | (_) |  __/| | | ||  _  | / ___ \ | |_) )
  \___/|  __/ \___/|_| |_||_| |_|/_/   \_\|____/
       |_|       4.3.5 - Release Build

Use '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
To exit, use '<ctrl-d>' or 'logout'.

It is weird that it says ‘permission denied’…unless something openhab is running and a set of files are locked and another instance cant acces the files. I have no idea how that could have happened as I just followed the install directions. Nothing easy is ever easy…