Problem with Anel HUT in latest snapshot (openHAB 2.4.0 Build #1399)

Dim · November 25, 2018, 12:04pm

no idea, but I didn’t see anyone posting problems related with java.net.SocketException: maximum number of DatagramSockets reached and searching github for DatagramSockets in the openhab organization shows nothing: Repository search results · GitHub

I would say: binding problem (UDP leak)

I don’t know why ss -u -a does not show up anything on your system… that’s very strange.

here is the output from my system:

root@homer:~# ss -u -a
State       Recv-Q Send-Q                                            Local Address:Port                                                Peer Address:Port   
ESTAB       0      0                                                     127.0.0.1:57366                                                  127.0.0.1:59535   
UNCONN      0      0                                                 172.16.13.100:domain                                                         *:*       
UNCONN      0      0                                                     127.0.0.1:domain                                                         *:*       
UNCONN      0      0                                                             *:bootps                                                         *:*       
UNCONN      0      0                                                             *:sunrpc                                                         *:*       
UNCONN      0      0                                                 172.16.13.100:ntp                                                            *:*       
UNCONN      0      0                                                     127.0.0.1:ntp                                                            *:*       
UNCONN      0      0                                                             *:ntp                                                            *:*       
UNCONN      0      0                                                 172.16.13.100:58019                                                          *:*       
UNCONN      0      0                                                             *:supfilesrv                                                        *:*       
UNCONN      0      0                                                     127.0.0.1:881                                                            *:*       
UNCONN      0      0                                                             *:21474                                                          *:*       
UNCONN      0      0                                                             *:mdns                                                           *:*       
UNCONN      0      0                                                             *:10001                                                          *:*       
ESTAB       0      0                                                     127.0.0.1:59535                                                  127.0.0.1:57366   
UNCONN      0      0                                                             *:39618                                                          *:*       
UNCONN      0      0                                                            :::3671                                                          :::*       
UNCONN      0      0                                          ::ffff:172.16.13.100:56933                                                         :::*       
UNCONN      0      0                                                            :::57062                                                         :::*       
UNCONN      0      0                                                            :::domain                                                        :::*       
UNCONN      0      0                                                            :::sunrpc                                                        :::*       
UNCONN      0      0                                 fe80::a28c:fdff:fe76:d3c%eth0:ntp                                                           :::*       
UNCONN      0      0                                                           ::1:ntp                                                           :::*       
UNCONN      0      0                                                            :::ntp                                                           :::*       
UNCONN      0      0                                                            :::supfilesrv                                                       :::*       
UNCONN      0      0                                                            :::mdns                                                          :::*       
UNCONN      0      0                                                            :::mdns                                                          :::*       
UNCONN      0      0                                          ::ffff:172.16.13.100:46641                                                         :::*       
UNCONN      0      0                                                            :::58965                                                         :::*       
UNCONN      0      0                                                            :::10001                                                         :::*       
UNCONN      0      0                                                            :::10001                                                         :::*       
UNCONN      0      0                                                            :::1900                                                          :::*       
UNCONN      0      0                                          ::ffff:172.16.13.100:35140                                                         :::*       
UNCONN      0      0                                                            :::3478                                                          :::*       
root@homer:~# ss -s
Total: 456 (kernel 543)
TCP:   368 (estab 187, closed 127, orphaned 0, synrecv 0, timewait 124/0), ports 383

Transport Total     IP        IPv6
*	  543       -         -        
RAW	  1         1         0        
UDP	  34        16        18       
TCP	  241       167       74       
INET	  276       184       92       
FRAG	  0         0         0        

root@homer:~#

edit: are you running the command as root?

yves · November 25, 2018, 12:07pm

do you have other software otehr then openhab running on the system?
Everything else I needed, I run on different raspberry pi’s.

Dim · November 25, 2018, 12:07pm

yeah, a sh!t load (dns, ntp, dhcp, many other using UDP sockets)

i use a mid-range Laptop to run Debian and everything I need on it

yves · November 25, 2018, 12:08pm

what is strange about being a binding problem, is that it started with 1.3 and I did not have it with 1.2

yves · November 25, 2018, 12:09pm

I ran it both with sudo and without sudo, same reply

Dim · November 25, 2018, 12:09pm

you may have another issue also that could affect the binding performance…

I don’t like this:

Low configured threads: (max=8 - required=1)=7

you may be running out of resources (for some reason) and this could cause UDP leak (I am just guessing)

Dim · November 25, 2018, 12:10pm

check this: "Low configured threads" warning

yves · November 25, 2018, 12:15pm

I did not have that warning today.
I’m trying to follow what needs to be done for that.

y

yves · November 25, 2018, 7:05pm

@paphko do you have any idea what could case this error?
Before I file a bug for this, I prefer to know a little more. Did you ever have this error?

yves · November 25, 2018, 10:33pm

I made a change for the threads, yet at 22:55 tonight I had again a

22:55:02.636 [ERROR] [ing.anel.internal.AnelConnectorThread] - Error occurred when sending UDP data to Anel device: 'wer da?'
java.lang.Exception: java.net.SocketException: maximum number of DatagramSockets reached
	at org.openhab.binding.anel.internal.AnelUDPConnector.sendDatagram(AnelUDPConnector.java:140) ~[230:org.openhab.binding.anel:1.13.0.M5]
	at org.openhab.binding.anel.internal.AnelConnectorThread.requestRefresh(AnelConnectorThread.java:208) [230:org.openhab.binding.anel:1.13.0.M5]
	at org.openhab.binding.anel.internal.AnelBinding.refreshAll(AnelBinding.java:149) [230:org.openhab.binding.anel:1.13.0.M5]
	at org.openhab.binding.anel.internal.AnelBinding.execute(AnelBinding.java:140) [230:org.openhab.binding.anel:1.13.0.M5]
	at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:144) [195:org.openhab.core.compat1x:2.4.0.M5]
	at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:166) [195:org.openhab.core.compat1x:2.4.0.M5]
Caused by: java.net.SocketException: maximum number of DatagramSockets reached
	at sun.net.ResourceManager.beforeUdpCreate(ResourceManager.java:73) ~[?:?]
	at java.net.AbstractPlainDatagramSocketImpl.create(AbstractPlainDatagramSocketImpl.java:77) ~[?:?]
	at java.net.DatagramSocket.createImpl(DatagramSocket.java:337) ~[?:?]
	at java.net.DatagramSocket.<init>(DatagramSocket.java:239) ~[?:?]
	at java.net.DatagramSocket.<init>(DatagramSocket.java:196) ~[?:?]
	at org.openhab.binding.anel.internal.AnelUDPConnector.sendDatagram(AnelUDPConnector.java:136) ~[?:?]
	... 5 more

Dim · November 25, 2018, 10:35pm

how come this shows M5?
I thought that you are on Snapshots
can you try to upgrade to M6?
I don’t think that it will solve your problem but you never know
this smells like a UDP Socket Leak on behalf of the Anel binding

github.com

openhab/openhab1-addons/blob/1924f5b40dfd1d96e0ae3f0a9280e57daa45fbbf/bundles/binding/org.openhab.binding.anel/src/main/java/org/openhab/binding/anel/internal/AnelConnectorThread.java#L130


      
                  if (!switchLocked) {
          
                      // Format to switch on: Sw_on<nr><user><pwd>
                      // Format to switch off: Sw_off<nr><user><pwd>
                      // Example: Sw_on3adminanel
                      final String cmd = "Sw_" + (newState ? "on" : "off") + switchNr + user + password;
                      logger.debug("Sending to " + connector.host + ":" + connector.receivePort + " -> " + cmd);
                      try {
                          connector.sendDatagram(cmd.getBytes());
                      } catch (Exception e) {
                          logger.error("Error occurred when sending UDP data to Anel device: " + cmd, e);
                      }
                  } else {
                      logger.debug("switch " + switchNr + " is locked, nothing sent.");
                  }
              } else {
                  logger.debug("switch " + switchNr + " lock state not yet initialized, nothing sent.");
              }
          }
          
          /**

Dim · November 25, 2018, 10:44pm

Open an Issue, put a bounty on it and ask other developers with experience in UDP Socket handling from other bindings (or general Java) to look into the way the binding creates and tears down UDP Sockets using its connector.

yves · November 25, 2018, 10:45pm

yes I’m on M5.

I did not have time to upgrade this weekend. With exams coming up for the kids, I’m not sure I will the next weekends.
Like I said, it started when Openhab swapped the addon’s from 1.2 to 1.3
I did not see any UDP changes in the M6.

Dim · November 25, 2018, 10:46pm

I doubt that there are any. In my opinion, the root cause is the way that the binding handles UDP connections.
This part of the binding code has not been updated for 3 years now (of course, if the code was optimized, you wouldn’t need to update it)
there was only a small update to it to remove plain text passwords logging

yves · November 25, 2018, 10:59pm

there was only a small update to it to remove plain text passwords logging

I saw that, they did miss some passwords logging, I filed a bug for that today.

The fact that I get a

“wer da?”

worries me, as that sounds like something that the developer had no idea when something happened.

Dim · November 25, 2018, 11:01pm

Well… we do have to respect that he sat down 4 years ago and build something for the community
It is a pitty that no-one else followed on his foot steps to further develop, maintain and enhance the Anel binding

paphko · February 28, 2019, 12:56pm

Sorry that I did not see this issue earlier!
I still use the binding and it works without any issues in my setup (OH 2.3).
My time is currently limited, but @Dim is right: maybe someone can review the socket connection code, I’m not an expert for that part…

The “wer da?”, however, belongs to the API of the Anel devices. It means “who is there?” and lets all Anel devices respond with a brief status message.

yves · March 1, 2019, 3:29pm

thanks.

I did make a proposal on github some time ago for removing of more password code.
I did that just by browsing the code, not by building it. (I don’t have any java editor on my machine)

I hope someone wants to check these in the future.
As passwords in logging is not secure…

I have +20 anel huts and I’m really happy with the binding.

Patrick did you see the discussions on OH3.0 and possibility of 1.x binding being removed in the future?

paphko · March 5, 2019, 10:22am

Please post links to these issues / pull requests, then I can have a look at them.

No, I did not read anything about OH3 plans yet…

yves · March 5, 2019, 12:46pm

Password in logs

Error message about wrong password