Remote openHAB - stopped working

binderth · August 9, 2021, 12:58pm

Since a few days (don’t know, what happened?), remote openhab stopped working.
It worked since setting it up in January, but now:

Thing was green(!)
No item values where updated
Disabling the binding and starting it again => Thing stays in “unknown” state

I set the binding to trace in the console

log:set TRACE org.openhab.binding.remoteopenhab

Log says:

2021-08-09 14:47:55.550 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'remoteopenhab:server:192_168_xx_yy' changed from UNINITIALIZED (DISABLED) to INITIALIZING
==> /var/log/openhab/openhab.log <==
2021-08-09 14:47:55.560 [DEBUG] [l.handler.RemoteopenhabBridgeHandler] - Initializing remote openHAB handler for bridge remoteopenhab:server:192_168_xx_yy
2021-08-09 14:47:55.561 [DEBUG] [l.handler.RemoteopenhabBridgeHandler] - REST URL = http://192.168.xx.yy:8080/rest
==> /var/log/openhab/events.log <==
2021-08-09 14:47:55.563 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'remoteopenhab:server:192_168_xx_yy' changed from INITIALIZING to UNKNOWN

REST-API is available and responding:

[14:55:23] openhabian@openhabMain:~$ curl http://192.168.xx.yy:8080/rest -I -vs
* Expire in 0 ms for 6 (transfer 0x1c08b0)
*   Trying 192.168.xx.yy...
* TCP_NODELAY set
* Expire in 200 ms for 4 (transfer 0x1c08b0)
* Connected to 192.168.xx.yy (192.168.xx.yy) port 8080 (#0)
> HEAD /rest HTTP/1.1
> Host: 192.168.xx.yy:8080
> User-Agent: curl/7.64.0
> Accept: */*
>
< HTTP/1.1 302 Found
HTTP/1.1 302 Found
< Location: http://192.168.xx.yy:8080/rest/
Location: http://192.168.xx.yy:8080/rest/
< Content-Length: 0
Content-Length: 0
< Server: Jetty(9.4.40.v20210413)
Server: Jetty(9.4.40.v20210413)

<
* Connection #0 to host 192.168.xx.yy left intact

What can I do?

rlkoshak · August 9, 2021, 3:19pm

What happens if you restart the remote OH instance? Maybe you need to restart that and then restart the Remote Binding bundle.

I used the binding for awhile without problem but moved back to the MQTT Event Bus implementation when I wrote the JavaScript version recently (see openhab-rules-tools/mqtt_eb at main · rkoshak/openhab-rules-tools · GitHub) and was too lazy to move back. But it worked great while I used it. Maybe there is a new bug that was introduced or something like that.

binderth · August 9, 2021, 3:34pm

Yeah, sorry, I forgot: I restarted the second instance, but not main yet.
also moved to MQTT based

rlkoshak · August 9, 2021, 3:57pm

It might be worth filing an issue on it. I know I’ve been recommending people use it all over the place and I hate to be doing that if there is a problem with it.

I don’t really have any further ideas for additional information to gather. Maybe putting the binding into debug log and gather logs at boot and when restarting the Thing.

Lolodomo · August 9, 2021, 6:22pm

If it works well during 7 months and suddenly it does no more work, you have to identify what changes. Did you update something? Is your remote server running? On the same address?
I doubt seriously there is suddenly a bug in the binding, especially while there were almost no changes…

binderth · August 9, 2021, 6:55pm

No changes in network topology, no configuration changes. Only thing updated are the Pi’s apt sources and there was some changes in the rasberry-kernel. But I don’t think, this is the cause?

Rest-API works on the secondary OH3 as intended. I’ll find the time to reboot the Main OH3 and try to get a full TRACE of it then.

binderth · August 10, 2021, 8:00am

Just changed the remote IP address to one, which doesn’t exist, same thing happens[1]. What dependencies does the remote openhab Binding have? (http binding works though!)

Is there a way to access/activate the jetty-logfile?

[1]

debug states connection is about to be made
state of thing changes to unknown and stays there

Lolodomo · August 10, 2021, 9:07am

You should at least see this DEBUG log: “Try the root REST API…”. Do you see it?

binderth · August 10, 2021, 11:05am

no. just the one lines I posted earlier - and that’s either with the IP from the second openHAB instance or with one, that doesn’t exist in my network. No “try the root REST API” or no error like “couldn’t find the remote openhab server”?

2021-08-10 13:02:31.831 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'remoteopenhab:server:192_168_xx_yy' changed from UNINITIALIZED (DISABLED) to INITIALIZING
==> /var/log/openhab/openhab.log <==
2021-08-10 13:02:31.838 [DEBUG] [l.handler.RemoteopenhabBridgeHandler] - Initializing remote openHAB handler for bridge remoteopenhab:server:192_168_xx_yy
2021-08-10 13:02:31.841 [DEBUG] [l.handler.RemoteopenhabBridgeHandler] - REST URL = http://192.168.xx.yy:8080/rest
==> /var/log/openhab/events.log <==
2021-08-10 13:02:31.843 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'remoteopenhab:server:192_168_xx_yy' changed from INITIALIZING to UNKNOWN

with an IP, that doesn’t fit:

2021-08-10 13:04:15.437 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'remoteopenhab:server:192_168_xx_yy' changed from UNINITIALIZED (DISABLED) to INITIALIZING
==> /var/log/openhab/openhab.log <==
2021-08-10 13:04:15.445 [DEBUG] [l.handler.RemoteopenhabBridgeHandler] - Initializing remote openHAB handler for bridge remoteopenhab:server:192_168_xx_yy
2021-08-10 13:04:15.447 [DEBUG] [l.handler.RemoteopenhabBridgeHandler] - REST URL = http://192.168.xx.zzz:8080/rest
==> /var/log/openhab/events.log <==
2021-08-10 13:04:15.449 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'remoteopenhab:server:192_168_xx_yy' changed from INITIALIZING to UNKNOWN

That’s all I get…?

Lolodomo · August 10, 2021, 4:41pm

The log entry I mentioned is the next action just after setting the thing state to UNKNOWN. But this is done in a separate thread. The only reason I am currently imagining is a problem you have to create threads !

github.com

openhab/openhab-addons/blob/main/bundles/org.openhab.binding.remoteopenhab/src/main/java/org/openhab/binding/remoteopenhab/internal/handler/RemoteopenhabBridgeHandler.java#L171

    
      
          
          
    restClient.setRestUrl(urlStr);
              restClient.setAuthenticationData(config.authenticateAnyway, config.token, config.username, config.password);
              if (config.useHttps && config.trustedCertificate) {
                  restClient.setHttpClient(httpClientTrustingCert);
                  restClient.setTrustedCertificate(true);
              }
          
          
    updateStatus(ThingStatus.UNKNOWN);
          
          
    scheduler.submit(() -> checkConnection(false));
              if (config.accessibilityInterval > 0) {
                  startCheckConnectionJob(config.accessibilityInterval, config.aliveInterval, config.restartIfNoActivity);
              }
          }
          
          
@Override
          public void dispose() {
              logger.debug("Disposing remote openHAB handler for bridge {}", getThing().getUID());
              stopStreamingUpdates(false);
              stopCheckConnectionJob();

github.com

openhab/openhab-addons/blob/main/bundles/org.openhab.binding.remoteopenhab/src/main/java/org/openhab/binding/remoteopenhab/internal/handler/RemoteopenhabBridgeHandler.java#L354

    
      
                      for (RemoteopenhabCommandOption option : commandOptions) {
                          options.add(new CommandOption(option.command, option.label));
                      }
                      commandDescriptionProvider.setCommandOptions(channel.getUID(), options);
                      logger.trace("{} command options set for the channel {}", options.size(), channel.getUID());
                  }
              }
          }
          
          
public void checkConnection(boolean restartSse) {
              logger.debug("Try the root REST API...");
              try {
                  restClient.tryApi();
                  if (restClient.getRestApiVersion() == null) {
                      updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.CONFIGURATION_ERROR,
                              "OH 1.x server not supported by the binding");
                  } else if (getThing().getStatus() != ThingStatus.ONLINE) {
                      List<RemoteopenhabItem> items = restClient.getRemoteItems("name,type,groupType,state,stateDescription");
          
          
            if (createChannels(items, true)) {
                          setDynamicOptions(items);

Of course, you are not running a fully outdated version of the binding ?

binderth · August 11, 2021, 6:00am

Hmm. How can I check this? I had an issue with memory leaks of amazonechocontrol Binding (openHAB 3.1: problems with ThreadPoolExecutor and subsequenlty OutOfMemory errors), but I solved this for now. Memory should not be an issue.

And yeah, I’m running 3.1.0 on both instances.

Lolodomo · August 11, 2021, 7:40am

The problem appears when you updated all your OH servers to OH3.1 ?
Others changes just before the problem appears?

binderth · August 11, 2021, 8:36am

I updated to OH 3.1 longer than the errors. The errors appeared only a few days ago - the only thing I changed (and I am aware of…!) is the new Rasbpian kernel, coming out? I had the error on about the 5th of August, as I updated this:

-rw-r--r-- 1 root root    847240 Aug  5 20:17 libraspberrypi0_1%3a1.20210805-1_armhf.deb
-rw-r--r-- 1 root root    341112 Aug  5 20:17 libraspberrypi-bin_1%3a1.20210805-1_armhf.deb
-rw-r--r-- 1 root root    400288 Aug  5 20:17 libraspberrypi-dev_1%3a1.20210805-1_armhf.deb
-rw-r--r-- 1 root root  31408268 Aug  5 20:17 libraspberrypi-doc_1%3a1.20210805-1_armhf.deb
-rw-r--r-- 1 root root   1011520 Aug  5 20:17 linux-libc-dev_1%3a1.20210805-1_armhf.deb
-rw-r--r-- 1 root root   4517888 Aug  5 20:17 raspberrypi-bootloader_1%3a1.20210805-1_armhf.deb
-rw-r--r-- 1 root root  79611860 Aug  5 20:17 raspberrypi-kernel_1%3a1.20210805-1_armhf.deb

I’m doing a reboot just now and now my log is flooded with DEBUG-entries for the remoteopenhab binding! seems to work just fine again! having an eye on it, though!

binderth · August 11, 2021, 8:51am

on further investigation I’d say that Update messed up pretty bad. So I just found out, that also my persistences dropped out since then, without me noticing it (don’t check my stats every day) - and I guess I have to set up some monitoring for my OH3!
My rules and stuff worked though… strange.

Rbartlett · October 25, 2021, 9:52pm

I had the same issue after updating to 3.1.0 on all my servers. I could no longer connect to my 3 remotes. I changed the API Token and still no luck. I had to turn Connect Anyways on to make this work. Since doing that I have never had a disconnect and the things always connect even after a reboot. Seems like some issue with remote authentication in 3.1.0 .