daniel-2k / ioBroker.nanoleaf-lightpanels

ioBroker Adapter for nanoleaf Light Panels / Canvas
MIT License
11 stars 4 forks source link

Error: No ssdp:alive detected. Try to reconnect... since 1.0.1 version #16

Closed WernerRH21 closed 4 years ago

WernerRH21 commented 4 years ago

I am a big fan of your iobroker.nanoleaf-lightpanels adapter and it worked really fine, until I updated to version 1.0.1. Every 2 minutes approx., a warning entry „Error: No ssdp:alive detected. Try to reconnect...“ is added tot he iobroker log file. In the meantime, the canvas lightpanels switch correctly to „Power State: true“ when presence detection state is true. My Canvas are correctly installed with firmware 1.6.2. I really appreciate your help. Thanks so far. 2020-07-06 10_22_28-logs - ioBroker

daniel-2k commented 4 years ago

Hello Werner,

this is a known problem which was also detected yesterday by another user. Because I have no Canvas device it could be problems with canvas devices. Problem of this behaviour is, that the nanoleaf devices are sending a SSDP notify message to indicate that they are still there. For indentification of nanoleaf devices they use different notification types for Light Panels and Canvas, which is not differentiated in the adapter. So the adapter does not recognize the keep alive messages and disconnects and connects each time. I created a developer version where I (hopefully) fixed this. You can try this.

You can also follow also in the ioBroker Forum thread: https://forum.iobroker.net/topic/34961/test-adapter-nanoleaf-lightpanels-v1-0-x-github-latest

Strunzdesign commented 4 years ago

I have the same problem with a Nanoleaf Aurora. "tcpdump" shows that UDP packets at port 1900 arrive, but they seem not to reach the nanoleaf adapter... most likely due to my "Shorewall" firewall. I fiddled around and still failed to get it working, kind of a mess... I found there is also my MythTV backend server that grabbed port 1900 before:

powerstation ~ # netstat -tulpen  | grep 1900          
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       1603953    19606/io.nanoleaf-l 
udp        0      0 255.255.255.255:1900    0.0.0.0:*                           104        20476      8868/mythbackend    
udp        0      0 239.255.255.250:1900    0.0.0.0:*                           104        20474      8868/mythbackend    
powerstation ~ # 

Is it "possible / allowed" that multiple applications can bind on the same IP address + UDP port number at the same time? I know this is UDP multicasting, so that MAY work, but I'm not sure yet. If only one application may bind to UDP port 1900 then this'll be a big regression for my system.

Any clues how to continue with this? Currently, I'm on version 1.0.1 that is flooding my log with the above mentioned SSDP error message. Maybe just a firewall issue, I'm going to investigate more. Is there a possibility to disable SSDP and get the old behavior back?

Regards, Florian

Strunzdesign commented 4 years ago

I gave up. Even with MythBackend disabled and this ioBroker adapter being the only application binding to port 1900, the error messages remain. Thus far, I added IP multicast support to my kernel and tested lots of stuff, but finally I had to downgrade back to the stable adapter and wait until this works better or until those SSDP checks can be disabled.

If I can help you debug this somehow, please let me know. Currently I'm out of ideas. Doesn't work here.

Regards, Florian

Strunzdesign commented 4 years ago

... this really seems to be a problem with my system, not with your adapter! On a second box I'm able to receive this multicast IP traffic easily even with shorewall running, but on my router (the box with ioBroker on it) I only see the traffic in tcpdump. Seems to be related to the fact that here multiple interfaces are bound together using a bridge (br0) and that this is the root cause. Still investigating...

daniel-2k commented 4 years ago

It's not a problem of your network or firewall configuration. The packets are reaching the adapter. But they are not process, because the Canvas use a different Notification type for identification. I fixed this in the adapter with version 1.0.2. Please try. It should now work.

Regarding binding multiple application can bind to the same IP-Adresse and port. I think in case of node JS it should be possible. I have two nanoleaf devices which are running of course in two different ioBroker adapter and as well 2 different node JS process. Both can receive the SSDP messages. But I think in case of these UDP multicast messages the process will not bind exclusively to this port. It is possible that multiple process can get these multicast messages.

But as I wrote, the problem is not a firewall related issue (of course, it can be). But with version 1.0.0 and 1.0.1 there is no differentiation between notification type of Light Panels and Canvas devices so these SSDP:alive messages were just ignored. Try 1.0.2 and report if this works.

Strunzdesign commented 4 years ago

Thank you very much! I'm going to test it as soon as it hits my "latest" repo here... the sync seems to need some time. And yes, I just tested concurrent reception of multicast packets using two entities of a python script on the same box and both receive the same copies of incoming data. Nice to know :-) I'm going to report you my results tomorrow!

Regards, Florian

Strunzdesign commented 4 years ago

Hi,

I installed your adaper 1.0.2 and the error persists. I was able to debug this further and to fix one of my issues on my system. At first, you MUST have set a route to your local LAN for 239.255.255.250/32 before you start any multicast listener applications. Otherwise, you end up having your application being bound on your outgoing interface (ppp0 here) without being able to receive any of your LAN multicasts. After fixing this, my python test script receives and prints multicast messages, but the ioBroker adapter remains deaf.

I found the problem: the adaptor binds to an arbitrary interface, which is my first Ethernet NIC in my router. As I have a bridged LAN, the adaptor shall bind to "br0" instead of "enp1s0". No idea how the adaptor selects this specific NIC, but it should not select one itself, but let the system decide to select the interface based on the routing table. My python script does not specify an interface and binds to the correct interface, that is br0.

powerstation ~ # ip maddr show dev enp1s0
3:      enp1s0
[...cut...]
        inet  239.255.255.250       <------ This is the nanoleaf adaptor
        inet  224.0.0.1
[...cut...]
powerstation ~ # ip maddr show dev br0
14:     br0
[...cut...]
        inet  239.255.255.250 users 2   <------ This is the MythBackend and the Python test receiver script
        inet  224.0.0.1
[...cut...]
powerstation ~ # 

Hope that helps, Florian

Strunzdesign commented 4 years ago

Hmm now it kind of works... the error messages are gone(?), but the application is still bound to a dead interface being part of a bridge. As a netcat "nc -v -l -u -p 1900 -s 239.255.255.250" shows all multicast messages of my LAN now, I assume that the adapter will get what it needs despite that oddity.

As it seems to work for now, its okay :-) Thanks!

Regards, Florian

daniel-2k commented 4 years ago

Hi Florian,

good to hear, that it works for you. But I will also try to analyze something. I develop and test the adapter on Windows environment, where I have no problems regarding binding of the adapter. I will try this on a Linux environment the next days. The problem regarding interface binding is, that I use a library for the SSDP UPNP messages. And there I have no influence on which interface the SSDP listener binds. Maybe I can find a solution where you can select the interface in Admin config page. But for this I need a SSDP library where I can set this. For now it's okay when it works, but I will also try to get a bit experience on Linux environment. What I'm worried about is that you have to create a route for the Multicast adress to the local network. I thought that Multicast messages will be sent to each interface. For example on Windows you do not need to set up any routes for this.

Strunzdesign commented 4 years ago

Here, without a dedicated route for multicast UDP traffic port 1900 towards my LAN, the router on which ioBroker is running determines a route to 239.255.255.250 via the default gateway behind ppp0. Then, ppp0 seems to be the preferred port to bind on (as seen via "ip maddr show"), and incoming traffic to port 1900 seems to come from ppp0 and is dropped by my firewall (of course!). However, these are assumptions, I do not understand the routing schemes completely to be sure!

powerstation ~ # ip route get 239.255.255.250           
multicast 239.255.255.250 dev ppp0 src AAA.BBB.CCC.DDD uid 0         <---- external world-wide IPv4 address
    cache <mc> 
powerstation ~ # ip route add 239.255.255.250/32 dev br0
powerstation ~ # ip route get 239.255.255.250           
multicast 239.255.255.250 dev br0 src 192.168.1.1 uid 0 
    cache <local,mc> 
powerstation ~ # 

Thus, I have to add that route. It MAY be that without a firewall ioBroker MIGHT also catch the LAN multicast traffic despite being bound on ppp0, but that is not a sane way to go. By adding the route it seems that at least ppp0 is not used anymore, and then multicast traffic to port 1900 passes my set of firewall rules.

---- EDIT ----

Use "ip route add 224.0.0.0/4 dev br0" instead! ... with your LAN-side interface instead of br0, of course.

Strunzdesign commented 4 years ago

Hi,

1.) As I understood, the Nanoleaf Aurora sends UDP broadcasts that are consumed by the ioBroker adaptor. i ask myself whether this is this a one-way delivery for keep-alive purposes only, or should the adaptor also send UDP broadcasts back? At least, I do not see any, I have only TCP-based traffic between the adaptor and the Aurora and the one-way multicasts. I just want to check whether there should be "outgoing" traffic or not that may get lost here at the moment.

2.) The reception of multicasts by the adaptor does only work if I additionally start the Mythtv-Backend server! Without mythbackend, the ioBroker adaptor still fails with the now well-known timeout error. If I then start the mythbackend, the ioBroker adaptor stops failing and seems to be able to receive the multicasts. I guess(!) that this behavior is caused by the fact that the adaptor is still bound to the wrong interface, and that the mythbackend process kind of helps the routing mechanisms to channel the inbound multicast traffic also to such non-related interfaces.

Regarding (1), if this is only for keep-alive handling, why was the TCP connection "not enough" in the past? Or, regarding (2), does the binding to a wrong interface cause outgoing multicast traffic to vanish here causing some kind of degradation of my setup?

Regards, Florian

Strunzdesign commented 4 years ago

Hi,

I found a great link that explains the observed behavior of dealing with multicasts:

https://stackoverflow.com/questions/10692956/what-does-it-mean-to-bind-a-multicast-udp-socket

It explains that the NIC has to be aware of the multicast membership and that only then it starts accepting multicast traffic not only directed to its own MAC address, but also that directed to a broadcast MAC address. As your adapter "binds" (wrong term, later!) to a wrong interface on my system, the LAN-NIC (br0 in my case) is not aware of any multicast membership and thus ignores all broadcast frames. My mythbackend and my test script indeed, by assigning to the correct interface, set br0 in a mode to accept broadcasts and allow the ioBroker adapter to receive IP multicasts. Furthermore, I'm quite sure now that if the ioBroker adapter would send outgoing IP multicasts, they would be sent via my dead interface enp1s0 (that is consumed by br0), or via ppp0. In both cases, they are lost.

Currently, the only possibility to fix that issue reliably at least on GNU/Linux would be to assure that the adapter choses the correct interface. I explicitly do not want to say "bind to" because that is a step that is not required. Just to do things in the right way should suffice, as my test script just does what is decribed in the article: it binds to ANY_ADDR:1900 and later performs an IP_ADD_MEMBERSHIP on that socket using IP address 239.255.255.250. No further steps are required to end up with a perfect IP multicast endpoint that is assigned correctly, which can be verified by "ip maddr show". Of course, SO_REUSEADDR is also a good idea :-)

Regards, Florian

Strunzdesign commented 4 years ago

The bug causing this issue resides in node-ssdp:

https://github.com/bazwilliams/node-ssdp/blob/a6d42afe5ffa7ba0e7804bb0118f55bea0762dae/index.js#L86

Here, the second parameter of "udpServer.addMembership(BROADCAST_ADDR, ip.address());" is the IP address of the interface to bind to, which is an optional parameter. Without that parameter, ALL interfaces would be bound to according to the documentation at:

https://node.readthedocs.io/en/latest/api/dgram/ search for "addMembership" and see what that second parameter means.

Worse, "ip.address()" delivers the first(!) local IP address of the system. In my case, this is the IP address 192.168.0.2 of my outgoing interface to my ADSL modem (for PPPoE) on enp1s0. I have to correct my previous statements, this interface is NOT part of a bridge, but a fullly configured LAN interface, to my PPPoE modem. Thus, the IP address to bind to should better be 192.168.1.1 of interface br0, or, as the even better choice, use 0.0.0.0. Oh, did I mention this is an optional parameter? Just drop it and let the routing table do its job!

This is the reason why the ioBroker adapter finally "binds" to the wrong interface here on my system. I'm going to file a bug report now and drop the link here.

Thanks again for this great adaptor. Lets make it even better now! :-)

Regards, Florian

Strunzdesign commented 4 years ago

... I know, I pointed out to a cloned repo. Ignore that for now.

Strunzdesign commented 4 years ago

I am confused, I'm a newbie in nodejs. According to https://www.npmjs.com/package/node-upnp-ssdp the module "node-upnp-ssdp" is also called "node-ssdp" and five years without contribution. Then there is a fresher repo (only two years since last commit) at https://github.com/diversario/node-ssdp. This has the same name. Which is the better choice for a bug report? Or, are you maybe using a deprecated repo, with "node-ssdp" being a better choice?

To speed things up, I leave it to you to decide and to report. Everything is clear now, but someone has to report that to get that one-liner fix in place.

Regards, Florian

Strunzdesign commented 4 years ago

Further information for you out there,

one MUST set a route to the LAN for multicast traffic to get routed in the correct direction. I read this multiple times, but closed all my tabs and have no link, unfortunately. Instead of setting a route matching 239.255.255.250/32, it is much better to use 224.0.0.0/4 instead.

Here on my system, setting this route manually would require "ip route add 224.0.0.0/4 dev br0" before starting any multicast listener applications.

Strunzdesign commented 4 years ago

This in fact fixes the problem:

powerstation node-upnp-ssdp # diff index.js index.js~
86c86
<     udpServer.addMembership(BROADCAST_ADDR);
---
>     udpServer.addMembership(BROADCAST_ADDR, ip.address());
powerstation node-upnp-ssdp # 

I'm filing a bug report now.

daniel-2k commented 4 years ago

Thank you for your research. I also have to read in this topic. First: the adapter do 2 things with SSDP. 1) receive the SSDP:alive messages for keep-alive (detect weather the device is still online). 2) for discovery the adapter seands SSDP MSEARCH requests and gets answer from each device which reacts on the service type. Regarding the binding: That's something I feared. You have a more special setup on your ioBroker host, because it acts as a router. The most common case is surly that the router is a sperate device, so most does not have this problem. You're right the node package I use for SSDP has no contribution in the last time. And there is also another node-ssdp package. But with this one I had problems because I didn't get the ssdp:alive messages to work (see also https://github.com/diversario/node-ssdp/issues/78). To clarify: the package I use is called "node-upnp-ssdp" on npm and the other "node-ssdp". On GitHub both has the same name, yes, but different devlopers. Our opend issue is correct.

daniel-2k commented 4 years ago

Hello Florian,

I changed now the package for SSDP processing to "peer-ssdp". I compared both packages. The "node-upnp-ssdp" determines the IP address of the local interface with the ip.address() method of the node "ip" package, which leads to your problem. "peer-ssdp" uses the internal node JS function os.networkinterfaces to do that. Please can you check how is the behaviour now? Unfortunately also in this package I cannot manually set the interface when creating the socket. But it is a try: Please try dev version 1.0.3: https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3

Strunzdesign commented 4 years ago

Hi,

great, I'm going to test it immediately. However, I downloaded it and it looks it MAY be sufficient to replace my /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels folder with your files, but how do I install all dependencies that need to be pulled in? I'm still a noob regarding nodejs :-)

Thank you very much, Florian

daniel-2k commented 4 years ago

HI,

please do not extract the tar archive into the nanoleaf node_modules folder. Install it via ioBroker Admin UI with the GitHub-Button (install from custom URL) on the top and then use custom tab and insert the URL posted. Then the dependencies will be automatically installed. Otherwise dependencies are missing.

Regards Daniel

NovalisVonHardenberg commented 4 years ago

HI,

please do not extract the tar archive into the nanoleaf node_modules folder. Install it via ioBroker Admin UI with the GitHub-Button (install from custom URL) on the top and then use custom tab and insert the URL posted. Then the dependencies will be automatically installed. Otherwise dependencies are missing.

Regards Daniel

v1.03 does not work.

nanoleaf-lightpanels.0 2020-08-02 11:46:22.117 error (19131) TypeError: Cannot read property 'val' of null at /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/main.js:643:57 at client.get (/opt/iobroker/node_modules/iobroker.js-controlle
nanoleaf-lightpanels.0 2020-08-02 11:46:22.116 error (19131) uncaught exception: Cannot read property 'val' of null

HI,

please do not extract the tar archive into the nanoleaf node_modules folder. Install it via ioBroker Admin UI with the GitHub-Button (install from custom URL) on the top and then use custom tab and insert the URL posted. Then the dependencies will be automatically installed. Otherwise dependencies are missing.

Regards Daniel

v1.03 does not work.

nanoleaf-lightpanels.0 2020-08-02 11:46:22.117 error (19131) TypeError: Cannot read property 'val' of null at /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/main.js:643:57 at client.get (/opt/iobroker/node_modules/iobroker.js-controlle
nanoleaf-lightpanels.0 2020-08-02 11:46:22.116 error (19131) uncaught exception: Cannot read property 'val' of null

Hi,

great, I'm going to test it immediately. However, I downloaded it and it looks it MAY be sufficient to replace my /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels folder with your files, but how do I install all dependencies that need to be pulled in? I'm still a noob regarding nodejs :-)

Thank you very much, Florian

I just use version 1.0 again, no problems anymore. image

daniel-2k commented 4 years ago

I just use version 1.0 again, no problems anymore.

Please do not use 1.0. You should use latest 1.0.2 because of bugfixes for Canvas devices. Should also work like 1.0 for Light Panels devices. Version 1.0.3 is an inoffical dev build for testing other SSDP library. Please test it only if you have problems with interface binding. The error you posted I have to check.

NovalisVonHardenberg commented 4 years ago

I just use version 1.0 again, no problems anymore.

Please do not use 1.0. You should use latest 1.0.2 because of bugfixes for Canvas devices. Should also work like 1.0 for Light Panels devices. Version 1.0.3 is an inoffical dev build for testing other SSDP library. Please test it only if you have problems with interface binding. The error you posted I have to check.

But with 1.02 i get "No ssdp:alive detected. Try to reconnect..." error.

daniel-2k commented 4 years ago

But with 1.02 i get "No ssdp:alive detected. Try to reconnect..." error.

Sorry, this cannot be. With version 1.0 the keep alive mechanism of receving the ssdp:alive messages from the nanoleaf devices was introduced. Between 1.0 and 1.0.1/1.0.2 there is only a bugfix for correct detecting the ssdp:alive messages and detection of firmware version for enabling SSE for Canvas devices. If you have a Canvas device 1.0 will never work (error "No ssdp:alive detected. Try to reconnect..." will come every time).

Regarding "No ssdp:alive detected. Try to reconnect...": this can have multiple reasons. It's not an issue with the adapter. Please look into the this ioBroker forum thread. Some people also have this issue. Its either firewall issue or Canvas devices are not sending these multicast messages anymore. Try power on/power off your nanoleaf device and look if it's away.

daniel-2k commented 4 years ago

Hi,

great, I'm going to test it immediately. However, I downloaded it and it looks it MAY be sufficient to replace my /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels folder with your files, but how do I install all dependencies that need to be pulled in? I'm still a noob regarding nodejs :-)

Thank you very much, Florian

Hello Florian,

have you already tested the version 1.0.3?

Regards Daniel

Strunzdesign commented 4 years ago

Hi Daniel,

thanks for your work, and sorry for the delay. Today I took the time to do a prober backup and then to start testing again.

At first, your adapter (1.0.3) works here. I get no timeouts, warnings, or errors. In debug mode, I can see all the broadcast traffic on UDP port 1900, originating from my Philips HUE bridge and from my Nanoleaf.

However, there is one issue. I saw LOTS of debug output regarding received messages, and got to the point that each message on the network is displayed 5 times in the logs of ioBroker / the adapter. This is caused by the Nanoleaf adapter that binds itself five times on my system:

powerstation ~ # netstat -tulpen  | grep 1900
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       16204091   16016/io.nanoleaf-l 
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       16204089   16016/io.nanoleaf-l 
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       16204087   16016/io.nanoleaf-l 
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       16204085   16016/io.nanoleaf-l 
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       16204083   16016/io.nanoleaf-l 
udp        0      0 255.255.255.255:1900    0.0.0.0:*                           104        188933     27672/mythbackend   
udp        0      0 239.255.255.250:1900    0.0.0.0:*                           104        188931     27672/mythbackend   
powerstation ~ # 

I have no idea why the adapter binds itself five times to the same address. Unfortunately, this results in a multiplication of each message to five times the amount necessary.

However, no big deal for now, the CPU will definitely handle it ;-) But would be nice to know why the adapter does that.

I can conduct more tests, so please let me know. I keep this version installed to see how it performs over the time.

Regards, Florian

Strunzdesign commented 4 years ago

Ok, more info:

By examination of the multicast routing table (ip maddr show), with and without the Nanoleaf adapter running, I see this difference:

First, there seems to be some logic in that new library to iterate over each of the available interfaces.Why it uses ppp0, and why it uses that twice, no idea. Second, the binding procedure seems odd as I receive one message of interface br0 multiple times, as if received over all of these five interfaces (four interfaces via five bindings) simultaneously.

daniel-2k commented 4 years ago

@Strunzdesign It's normal that you see a LOTS of SSDP messages in debug, because the new SSP library cannot fire events for specific notification types. I have to handle all messages from all devices and filter them in my callback routine. But that's no problem. You will only have some unnecessary fired events. Increasing of CPU load should not be noticeable. Interesting is the binding to each interface of your system (especially two times on one interface). Are you sure that the adapter process then the processes messages multiple times? I think not. You should see it in the debug log. There, all received SSDP notify messages from all device in your LAN will be logged. But each message should be logged one time (please note some device as FritzBox sends multiple SSDP notify messages, but nanoleaf devices only once per minute). I use Windows environment. I will check how many bindings on Window exists. But you have to admit, your configuration is already special. Most users will not have such configuration.

daniel-2k commented 4 years ago

I checked now Windows environment. There the node process binds only to my Ethernet adapter. But I analyzed the code: the library gets all network interfaces via os.networkInterfaces() and then over all interfaces and IP bindings will be iterated. A socket will be created for each interface which is IPv4 and not for internal use (e.g. loopback interface). I think it's wanted to receive all SSDP notify if you have more then one LAN adapter for local network or VLAN etc. Of course for your ppp0 it makes not sense. But normally the SSDP notify messages for the nanoleaf devices should only be received via br0, Via ppp0 you should not get such UDP multicasts. So is it a problem for you when the library binds on all not internal interfaces? Normally you should not have massive SSDP messages on all interfaces.

Strunzdesign commented 4 years ago

Hi,

it is exactly as I wrote it: any broadcast message coming in on interface br0 is displayed five times in the log (in debug mode). The time stamps differ only in about 1ms, so they are processed sequentially. This is probably caused by that multiple binding procedure.

As I discovered during the research of your previous library, it should be sufficient to (a) bind only once to IP_ADDR_ANY (0.0.0.0), (b) add one multicast subscription to that listener, and (c) to not to specify any interfaces but let the OS perform that decision based on the multicast routing table. Your first library was fixed easily by just removing that "bind to an arbitrary interface" stuff, but this new library seems to take a different approach. To be honest, this library does not look sane either, and it is orphaned and unsupported as well.

On the one hand, your adapter works for me now, the "multiplication" of messages is not a big issue for me, and having all interfaces involved is not a problem as I run a well-maintained firewall. On the other hand, network stacks are very complex stuff, and one can easily open holes if doing stuff wrong. By using orphaned libraries that do stuff wrong, you move a part of that underlying complexity to the users of your adapter. Such users normally do not possess the necessary background to debug networking stuff or to proactively work around possible security issues. I may have an unusual setup here, but to be honest, each system is unique and unusal by definition. We together should tackle this now once and for all, to avoid an endless series of bug reports caused by "normal router setups" in the future.

I do not want to critic, I want to help but also want to warn. I like this adapter very much and want to help. I want this to be solved for the long run. Thus, do you know subsequent multicast libraries? Is a fork or an inclusion of the fixed first library a solution?

Regards, Florian

Strunzdesign commented 4 years ago

I forgot to mention that the adapter now runs more than a full day without any warnings or errors in the log! :-)

daniel-2k commented 4 years ago

@Strunzdesign Unfortunately most of the node ssdp libraries are unsupported and the one which have still supportm does not work. Now I have forked the "node-upnp-ssdp" library and removed the IP address for the membership (removed the "bind to an arbitrary interface"). So please could you test the adapter again? It's the same release: https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3 Hope interface binding is now managed by OS correctly.

Strunzdesign commented 4 years ago

Hi,

sounds great. I tested it and got an error, and now the adapter is defect / not starting anymore. I got this error in the install window:

$ ./iobroker url "https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3"
install https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3
NPM version: 6.14.4
npm install https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3 --loglevel error --prefix "/opt/iobroker" (System call)
npm
 ERR! Unexpected string in JSON at position 760

npm ERR! A complete log of this run can be found in:npm ERR!     /home/iobroker/.npm/_logs/2020-08-16T21_00_20_342Z-debug.log
upload [7] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/words.js words.js application/javascript
upload [6] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/nanoleaf-lightpanels.png nanoleaf-lightpanels.png image/png
upload [5] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/index_m.html index_m.html text/html
upload [4] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/icons/rhythm.png icons/rhythm.png image/png
upload [3] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/icons/lightpanels.png icons/lightpanels.png image/png
upload [2] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/icons/canvas.png icons/canvas.png image/png
upload [1] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/i18n/en/translations.json i18n/en/translations.json application/json
upload [0] nanoleaf-lightpanels.admin /opt/iobroker/node_modules/iobroker.nanoleaf-lightpanels/admin/i18n/de/translations.json i18n/de/translations.json application/json
process exited with code 0

And the file /home/iobroker/.npm/_logs/2020-08-16T21_00_20_342Z-debug.log has this content:

powerstation florian # cat /home/iobroker/.npm/_logs/2020-08-16T21_00_20_342Z-debug.log
0 info it worked if it ends with ok
1 verbose cli [
1 verbose cli   '/usr/bin/node',
1 verbose cli   '/usr/bin/npm',
1 verbose cli   'install',
1 verbose cli   'https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3',
1 verbose cli   '--loglevel',
1 verbose cli   'error',
1 verbose cli   '--prefix',
1 verbose cli   '/opt/iobroker'
1 verbose cli ]
2 info using npm@6.14.4
3 info using node@v12.17.0
4 verbose npm-session d8536a1e01281248
5 silly install loadCurrentTree
6 silly install readLocalPackageData
7 http fetch GET 304 https://codeload.github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/legacy.tar.gz/dev_1.0.3 647ms (from cache)
8 silly fetchPackageMetaData error for https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3 Unexpected string in JSON at position 760
9 timing stage:rollbackFailedOptional Completed in 0ms
10 timing stage:runTopLevelLifecycles Completed in 2074ms
11 verbose stack SyntaxError: Unexpected string in JSON at position 760
11 verbose stack     at JSON.parse (<anonymous>)
11 verbose stack     at module.exports (/usr/lib64/node_modules/npm/node_modules/pacote/lib/util/read-json.js:14:15)
11 verbose stack     at /usr/lib64/node_modules/npm/node_modules/pacote/lib/finalize-manifest.js:209:22
11 verbose stack     at tryCatcher (/usr/lib64/node_modules/npm/node_modules/bluebird/js/release/util.js:16:23)
11 verbose stack     at Promise._settlePromiseFromHandler (/usr/lib64/node_modules/npm/node_modules/bluebird/js/release/promise.js:517:31)
11 verbose stack     at Promise._settlePromise (/usr/lib64/node_modules/npm/node_modules/bluebird/js/release/promise.js:574:18)
11 verbose stack     at Promise._settlePromise0 (/usr/lib64/node_modules/npm/node_modules/bluebird/js/release/promise.js:619:10)
11 verbose stack     at Promise._settlePromises (/usr/lib64/node_modules/npm/node_modules/bluebird/js/release/promise.js:699:18)
11 verbose stack     at Promise._fulfill (/usr/lib64/node_modules/npm/node_modules/bluebird/js/release/promise.js:643:18)
11 verbose stack     at /usr/lib64/node_modules/npm/node_modules/bluebird/js/release/nodeback.js:42:21
11 verbose stack     at ReadEntry.<anonymous> (/usr/lib64/node_modules/npm/node_modules/pacote/lib/util/finished.js:10:9)
11 verbose stack     at ReadEntry.emit (events.js:327:22)
11 verbose stack     at ReadEntry.emit (/usr/lib64/node_modules/npm/node_modules/tar/node_modules/minipass/index.js:414:25)
11 verbose stack     at ReadEntry.[maybeEmitEnd] (/usr/lib64/node_modules/npm/node_modules/tar/node_modules/minipass/index.js:355:12)
11 verbose stack     at ReadEntry.end (/usr/lib64/node_modules/npm/node_modules/tar/node_modules/minipass/index.js:235:27)
11 verbose stack     at Object.[consumeBody] (/usr/lib64/node_modules/npm/node_modules/tar/lib/parse.js:216:13)
12 verbose cwd /opt/iobroker
13 verbose Linux 5.7.8-gentoo
14 verbose argv "/usr/bin/node" "/usr/bin/npm" "install" "https://github.com/daniel-2k/ioBroker.nanoleaf-lightpanels/tarball/dev_1.0.3" "--loglevel" "error" "--prefix" "/opt/iobroker"
15 verbose node v12.17.0
16 verbose npm  v6.14.4
17 error Unexpected string in JSON at position 760
18 verbose exit [ 1, true ]
powerstation florian #

Hope this helps!

Regards, Florian

Strunzdesign commented 4 years ago

Ok the adapter works, maybe it needed some time to find to itself :-) However, I have five interface bindings active. What does this mean? This is the behavior as we have seen in the last version, not that of the version before. So the update did not succeed, I assume.

daniel-2k commented 4 years ago

@Strunzdesign Yes, I already got an error from appveyor. There is a typing mistake in the package.json and I forgot the forked lib. I just corrected it, please try again.

daniel-2k commented 4 years ago

@Strunzdesign No, please install again. It cannot work, because in the first commit I forgot the forked library. So this version you have installed is the old one.

Strunzdesign commented 4 years ago

Thanks, that worked, completely! Great work!

One binding is active, on the correct interface, shared with the mythbackend server. I see SSDP messages in the logs, without duplicates. The output of "ip maddr show" shows the expected behavior.

Again, this is a great result. Unfortunately, this seems to be that "nodejs hell" the people warn about... deep dependencies that to outdated stuff that no one has control over. Including these into the repo seems the best choice under such circumstances.

Now let's hope that no other issues arise if an increasing number of people test this.

Thanks for your work, Florian

daniel-2k commented 4 years ago

Very good! I'm happy :-). So then I will put this into a new offical version 1.0.3 and then I will close this issue.

Strunzdesign commented 4 years ago

Maybe you should put a hint somewhere regarding the multicast route, i.e., to set it once using ip route add 224.0.0.0/4 dev INTERFACE. Or just keep that in mind, in case there are people having problems.

Strunzdesign commented 4 years ago

I give you feedback again in 1-2 days. But I don't expect issues.

daniel-2k commented 4 years ago

Maybe you should put a hint somewhere regarding the multicast route, i.e., to set it once using ip route add 224.0.0.0/4 dev INTERFACE. Or just keep that in mind, in case there are people having problems.

But you the only one who needs this (where I have heard that this is neded). For all other users it seems to work with standard configuration. Also on linux environements. On Windows there is by default a 224.0.0.0 route. I think on linux too (maybe on some dists? I'm not a linux expert). Nevertheless this can be a point to look for it does not work.

Strunzdesign commented 4 years ago

Works well here so far! Regarding that route, you only really need that if your interface with the default route differs from your LAN interface. In most cases the way to your LAN is also the way towards your default gateway. I see at least two cases where this assumption becomes invalid: if you install ioBroker on a router such as I did, or, if you enable some privacy-enhancing VPN that has to redirect the default route through the VPN server. In both cases, adding a dedicated route for 224.0.0.0/4 towards the LAN interface solves this issues. However, no OS has the intelligence to add such a dedicated route by itself... one has to do that manually, if required.

Looking forward for the official version 1.0.3 now :-)

Thanks, and regards, Florian

EDIT: Windows sets such a route? One in total, or one for each interface? :-)

daniel-2k commented 4 years ago

One for each interface:

   Netzwerkziel    Netzwerkmaske          Gateway    Schnittstelle Metrik
        0.0.0.0          0.0.0.0      192.168.0.1     192.168.0.10     25
      127.0.0.0        255.0.0.0   Auf Verbindung         127.0.0.1    331
      127.0.0.1  255.255.255.255   Auf Verbindung         127.0.0.1    331
127.255.255.255  255.255.255.255   Auf Verbindung         127.0.0.1    331
    192.168.0.0    255.255.255.0   Auf Verbindung      192.168.0.10    281
   192.168.0.10  255.255.255.255   Auf Verbindung      192.168.0.10    281
  192.168.0.255  255.255.255.255   Auf Verbindung      192.168.0.10    281
      224.0.0.0        240.0.0.0   Auf Verbindung         127.0.0.1    331
      224.0.0.0        240.0.0.0   Auf Verbindung      192.168.0.10    281
255.255.255.255  255.255.255.255   Auf Verbindung         127.0.0.1    331
255.255.255.255  255.255.255.255   Auf Verbindung      192.168.0.10    281

One thing: can you try the search function in the adapter settings? I saw that the for the MSEARCH requestor also ip.adress() is used to bind on a specfific interface. Can you check if the function is working? If you want to check the bindung you have to call your command to display within 5 seconds after click the search button. Then the connection will be closed.

Strunzdesign commented 4 years ago

I get crashes of the discovery adapter. At first, which "method" is to use? "mDNS", "UDP", or "UPNP"? I think mDNS, but please confirm.

daniel-2k commented 4 years ago

It is UPNP. But I mean not via discovery adapter. I integrated nanoleaf devices into discovery adapter but the current version does not already include this. Please use the search function in the nanoleaf adapter admin config. This was introduced in version 1.0.0.

Strunzdesign commented 4 years ago

Ok, I didn't know that yet. I tested that, and that happens:

Thus, it seems not to work. Sorry. Florian

EDIT: This is the content of the log window:

nanoleaf-lightpanels.0 | 2020-08-19 23:32:45.940 | debug | (23057) sendTo "searchDevice" to system.adapter.admin.0 from system.adapter.nanoleaf-lightpanels.0
-- | -- | -- | --
nanoleaf-lightpanels.0 | 2020-08-19 23:32:45.939 | debug | (23057) MSEARCH: 0 devices found!
Strunzdesign commented 4 years ago

Ok, there is something:

powerstation florian # netstat -tulpen  | grep nanoleaf
udp        0      0 0.0.0.0:59042           0.0.0.0:*                           2002       2171046    23257/io.nanoleaf-l 
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           2002       2166829    23257/io.nanoleaf-l 

... but the adapter does not find the panel. That additional port is random.

daniel-2k commented 4 years ago

I made a litte change in the node-upnp-ssdp lib. Can you update the dev_1.0.3 again and try search devices again?

Strunzdesign commented 4 years ago

Hi,

I just tested it. Again, the search does not give a result. There is again this additional random UDP port that appears on the ioBroker-Server during scanning, but no additional entries appeared in the list of multicast addresses.

I was able to conduct some sniffing to check whats going over the line. As I have an all-bridged setup, I can easily sniff UDP multicasts of the nanoleaf device and the nanoleaf adapter on any of my PCs, so I did that. I used the command tcpdump -A -vvv port 1900 for sniffing, started on another PC in the LAN:

[...]
21:14:25.102189 IP (tos 0x0, ttl 1, id 36484, offset 0, flags [DF], proto UDP (17), length 314)
    [nanoleaf].1900 > 239.255.255.250.1900: [udp sum ok] UDP, length 286
E..:..@...8Z...2.....l.l.&aeNOTIFY * HTTP/1.1
Host: 239.255.255.250:1900
NT: nanoleaf_aurora:light
NTS: ssdp:alive
USN: uuid:aaaaaaaa-bbbb-cccc-dddd-eeeeeeeeeeee
Location: http://192.x.y.z:16021
Cache-Control: max-age = 60
nl-deviceid: AA:BB:CC:DD:EE:FF
nl-devicename: Nanoleaf Light Panels 01:23:45

21:14:38.798507 IP (tos 0x0, ttl 1, id 26263, offset 0, flags [DF], proto UDP (17), length 118)
    [server].58635 > 239.255.255.250.1900: [udp sum ok] UDP, length 90
E..vf.@...a<...........l.b..M-SEARCH * HTTP/1.1
Host:239.255.255.250:1900
ST:ssdp:all
Man:"ssdp:discover"
MX:2
[...]

The first exemplary message shows one of the nanoleaf multicasts, from UDP port 1900 to UDP port 1900. The second message is that message that is emitted during a press on the "seach" button in your adapter. So, (a) that message is created and (b) sent once (c) to at least my bridge device on the ioBroker server. But there is no reply on the LAN; the nanoleaf device just ignores it. Is it correct that the UDP source port number is random (58635) rather than 1900?

Regards, Florian