Homematic-Binding broken after update to openHAB 5.0

Hello,

today I made the update to openHAB 5.0. After a couple of problems, descripted in “breakilng changes” all bindings and things except homematic works fine.

The homematic-Bridge (Raspberrymatic latest release) and several homematic things are online. And when I send on or off to a switch thing, for exampte to open the garage door, it works. But I don’t get any periodic state update from every sensor. Only when I disable and enable the bridge I get the states from every switch or sensor.

What i have done since now is

  • cleaned the cache
  • removed the homematic binding an installed it again
  • removed the bridge and installed it again
  • removed things and added things

When I try to change the log level in the karaf console I get an error:

openhab> log:set TRACE org.openhab.binding.homematic
Error executing command: Unable to set level for logger

When I try to change the log level in the UI I get also an error:

2025-07-31 18:17:26.654 \[ERROR\] \[internal.JSONResponseExceptionMapper\] - Unexpected exception occurred while processing REST request.

java.lang.RuntimeException: Unable to set level for logger

	at org.apache.karaf.log.core.internal.LogServiceLog4j2XmlImpl.setLevel(LogServiceLog4j2XmlImpl.java:139) \~\[?:?\]

	at org.apache.karaf.log.core.internal.LogServiceImpl.setLevel(LogServiceImpl.java:114) \~\[?:?\]

	at org.openhab.core.karaf.internal.LoggerResource.putLoggers(LoggerResource.java:106) \~\[?:?\]

	at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) \~\[?:?\]

	at java.lang.reflect.Method.invoke(Method.java:580) \~\[?:?\]

	at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:179) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:201) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:104) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:265) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:225) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:304) \~\[bundleFile:3.6.5\]

	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPut(AbstractHTTPServlet.java:234) \~\[bundleFile:3.6.5\]

	at javax.servlet.http.HttpServlet.service(HttpServlet.java:520) \~\[bundleFile:4.0.4\]

	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:279) \~\[bundleFile:3.6.5\]

	at org.ops4j.pax.web.service.spi.servlet.OsgiInitializedServlet.service(OsgiInitializedServlet.java:102) \~\[bundleFile:?\]

	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656) \~\[bundleFile:9.4.57.v20241219\]

	at org.ops4j.pax.web.service.spi.servlet.OsgiFilterChain.doFilter(OsgiFilterChain.java:113) \~\[bundleFile:?\]

	at org.ops4j.pax.web.service.jetty.internal.PaxWebServletHandler.doHandle(PaxWebServletHandler.java:334) \~\[bundleFile:?\]

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) \~\[bundleFile:9.4.57.v20241219\]

	at org.ops4j.pax.web.service.jetty.internal.PrioritizedHandlerCollection.handle(PrioritizedHandlerCollection.java:96) \~\[bundleFile:?\]

	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:722) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.Server.handle(Server.java:516) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) \~\[bundleFile:9.4.57.v20241219\]

	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) \~\[bundleFile:9.4.57.v20241219\]

	at java.lang.Thread.run(Thread.java:1583) \[?:?\]

Caused by: org.w3c.dom.DOMException: NOT_FOUND_ERR: Es wurde versucht, einen Knoten in einem Kontext zu referenzieren, in dem er nicht vorhanden ist.

	at com.sun.org.apache.xerces.internal.dom.ParentNode.internalInsertBefore(ParentNode.java:364) \~\[?:?\]

	at com.sun.org.apache.xerces.internal.dom.ParentNode.insertBefore(ParentNode.java:286) \~\[?:?\]

	at org.apache.karaf.log.core.internal.LogServiceLog4j2XmlImpl.insertIndented(LogServiceLog4j2XmlImpl.java:168) \~\[?:?\]

	at org.apache.karaf.log.core.internal.LogServiceLog4j2XmlImpl.setLevel(LogServiceLog4j2XmlImpl.java:121) \~\[?:?\]

	... 59 more

Is there anybody else who updated to openHAB 5.0 and habe the homematic binding installed and can help?

I’m afraid I cannot really help with your issue, all I can say is that my Homematic binding is working fine, also with the latest release of Raspberrymatic. So this combination does work with 5.0

I did however flashed an SD card with the latest openHABian and then just copied all my textual configuration files onto it again, restarted and that was it.

With you upgrading form an existing openHAB 4.x.x system there might have gone something wrong during the upgrade.

Did you restart just once after clearing the cache? I find that at least two restarts are usually necessary to get everything working properly again.

I can’t address the Homematic part but the exception when changing the logger seems to indicate your log4j2.xml file might not be valid or otherwise corrupted. Look at that file and see if anything looks fishy.

I’m willing to bet it won’t let you change any logger and that this issue is separate from your Homematic issue.

It is always good to know that the combination have to work and the problem is not in the binding or Raspberrymatic :slightly_smiling_face:

Yes, you’re right two restarts after cleaning the cache is better. I made a lot of restarts more yesterday :sweat_smile:

But it looks like I found the problem. I take a closer look at the logfile. And there was a warning about multiple adapters and the IP from openHAB was ingnored. So I looked at the network configuration and there were to addreses and none of them was marked. So I marked the right IP and after a restart the homematic binding is working.

1 Like

You are right, the logger problem had nothing to do with the homematic problem.

So I looked at the log4j2.xml file and nothing looks fishy (nice saying :grinning_face: ) for me. But that doesn’t mean anything :sweat_smile: .

I saw there is a log4j2.xml.dpkg-dist in the folder. So I saved my log4j2.xml and renamed the log4j2.xml.dpkg-dist to log4j2.xml and made a restart. And now I can change the log level without exception. On occasion I will compare the two files to find what’s wrong.

Thank you for helping :slightly_smiling_face:

Hello Hape, i am facing the same problem. Could give me some hint, where exactly to check the network configuration? Thanks a lot.