Python plugin: Presence detection from wireless router

[hjzwiers]

Ok I will try and report back to you!

[rensbr]

I'm using the 2024.1 version with the original plugin now for about 24 hours and by the looks of it the memory problem looks good.

I started with 64% yesterday and the memory today is still 64%, so it looks promising.

[EscApe]

I'm using the 2024.1 version with the original plugin now for about 24 hours and by the looks of it the memory problem looks good.

I started with 64% yesterday and the memory today is still 64%, so it looks promising.

That is great to hear. Thanks for the feedback!

I have compared the old plugin to the latest beta (that uses paramiko again) and didn't see much difference after running for a few hours with a 3 second poll interval. Would you be willing to test that over a longer period?

The beta should use less memory to begin with because it doesn't load supporting python modules for tracker types that are not in use.

[rensbr]

I'm using the 2024.1 version with the original plugin now for about 24 hours and by the looks of it the memory problem looks good.

I started with 64% yesterday and the memory today is still 64%, so it looks promising.

That is great to hear. Thanks for the feedback!

I have compared the old plugin to the latest beta (that uses paramiko again) and didn't see much difference after running for a few hours with a 3 second poll interval. Would you be willing to test that over a longer period?

The beta should use less memory to begin with because it doesn't load supporting python modules for tracker types that are not in use.

I'm planning to run this setup for a few days to see what happens and switch to the beta version after that and compare the two.

[hjzwiers]

I'm running the old program but I keep getting the:
iDetect: Call to function 'onStart' failed, exception details:
2024-01-13 16:06:32.135 Error: iDetect: Traceback (most recent call last):
2024-01-13 16:06:32.135 Error: iDetect: File "/home/hjz/domoticz/plugins/iDetect/plugin.py", line 431, in onStart
2024-01-13 16:06:32.135 Error: iDetect: _plugin.onStart()
2024-01-13 16:06:32.135 Error: iDetect: File "/home/hjz/domoticz/plugins/iDetect/plugin.py", line 262, in onStart
2024-01-13 16:06:32.135 Error: iDetect: if get_domoticz_status(self.OVERRIDE_UNIT):
2024-01-13 16:06:32.135 Error: iDetect: File "/home/hjz/domoticz/plugins/iDetect/plugin.py", line 181, in get_domoticz_status
2024-01-13 16:06:32.135 Error: iDetect: if Devices[unit].nValue == True:
2024-01-13 16:06:32.135 Error: iDetect: KeyError: 255

When is the update coming?

[EscApe]

You need to install the beta. It has been solved.

[hjzwiers]

I am running the latest beta? Just updated

[EscApe]

The latest beta of Domoticz? (Because this was a Domoticz problem). What is the version and build number?
Is “accept new hardware devices” enabled in the settings?

[hjzwiers]

Yes, build 15836 and in settings I have accept new hardware devices enabled. I can disable and enable?
Just tried it same errors ....

And why is the enable for 5 minutes red ..... also tried it, pressed allow for 5 minutes and did an update, same errors.

I did run the Beta .... deleted it and reinstalled the original version.

Still the same error. Do I need to reset something?

[EscApe]

Yes, build 15836 and in settings I have accept new hardware devices enabled. I can disable and enable?
Just tried it same errors ....

And why is the enable for 5 minutes red ..... also tried it, pressed allow for 5 minutes and did an update, same errors.

I did run the Beta .... deleted it and reinstalled the original version.

Still the same error. Do I need to reset something?

Sorry, I cannot reproduce the problem. Tried on build 15810 using the database that previously generated the error. Also tried newly created databases (fresh install) and the same on build 15840 (=todays build).

The issue that has been fixed is that the newer Domoticz database design was expecting a value that a lot of hardware add-ins (including the plugin system) did not supply. So on a fresh install it was impossible to add anything from within a plugin. Updating an existing Domoticz instance was no problem, because it would still use the older database design.

What you could do is try other python plugins. Are they able to create devices?

You could also enable more logging in Domoticz to see if you can find the root source of this problem. The snippets of log you have shared so far do not reveal much. It basically only shows that the Domoticz device for the override unit does nog exist. There might be something in the full log showing why the creation of this device has failed. It there is no useful info you might want to enable debug logging for Domoticz (not just the plugin).

[hjzwiers]

I deleted everything and reinstalled, and it worked!

Don't know what it was....

I have one small error left:

2024-01-16 16:12:37.033 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-16 16:12:37.309 Status: IDetect: 192.168.2.178 ====> SSH resetting connection
2024-01-16 16:12:37.552 Status: IDetect: 192.168.2.38 ====> SSH resetting connection
2024-01-16 16:12:37.033 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.
2024-01-16 16:12:37.309 Error: IDetect: 192.168.2.178 ====> SSH failed with exception: Timeout opening channel.
2024-01-16 16:12:37.552 Error: IDetect: 192.168.2.38 ====> SSH failed with exception: Timeout opening channel.

I am not filling in a password in the router (should work without?), and I have filled in my user name and password in the settings.

I used to drive it with 192.168.2.1#type=brctl, now I am filling in the nodes. What is the best way?

[hjzwiers]

IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel

seems independant of the type of header, i keep getting the error above

I've installed the login in the server, it can now login the router without a password, but I used to be able to run command from the server in the router, but now I get errors.

[EscApe]

IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel

The only thing I can tell from this one line of information is that it does not look like authentication is the issue here. There seems te be no connection between Domoticz and the router. This is not related to the plugin and could have lots of reasons. From changed ip-addresses and misconfigured (docker) networks to firewalls or ssh servers blocking traffic from Domoticz ip-address.
Make sure you are testing from within the environment that is also running Domoticz. So if Domoticz is in a docker container you test from the cli in that docker container.

Of course there could be other (less likely) reasons that just lead to an unhelpful error message, but I wouldn't know where to start looking without knowing your setup and without a full debug log.

[hjzwiers]

I don't think there is a connection problem, its connecting and disconnecting all the time.

I see iDetect tracking on the router, but it is getting no result. I have a AC86u, three in mesh. I've tried all typs of extensions but I can't seem to get it right.

Right now I'm using 192.168.2.1#type=brctl, i've tried using the 192.168.2.1#ssh_aimesh_json.py but that also didn't work.

The issue is you need to dis-connect and connect every time.

[hjzwiers]

I cleared the directory of iDetect and reinstalled

ran the install

with the tracker 192.168.2.1#ssh=brcrl

this is the result

IDetect: 192.168.2.1 ====> SSH Fetching data using: brctl
2024-01-27 10:30:55.841 IDetect: 192.168.2.1 ====> SSH returned (decoded):Usage: brctl [commands]
2024-01-27 10:30:55.841 commands:
2024-01-27 10:30:55.841 addbr <bridge> add bridge
2024-01-27 10:30:55.841 delbr <bridge> delete bridge
2024-01-27 10:30:55.841 addif <bridge> <device> add interface to bridge
2024-01-27 10:30:55.841 delif <bridge> <device> delete interface from bridge
2024-01-27 10:30:55.841 hairpin <bridge> <port> {on|off} turn hairpin on/off
2024-01-27 10:30:55.841 setageing <bridge> <time> set ageing time
2024-01-27 10:30:55.841 setbridgeprio <bridge> <prio> set bridge priority
2024-01-27 10:30:55.841 setfd <bridge> <time> set bridge forward delay
2024-01-27 10:30:55.841 sethello <bridge> <time> set hello time
2024-01-27 10:30:55.841 setmaxage <bridge> <time> set max message age
2024-01-27 10:30:55.841 setpathcost <bridge> <port> <cost> set path cost
2024-01-27 10:30:55.841 setportprio <bridge> <port> <prio> set port priority
2024-01-27 10:30:55.841 show [ <bridge> ] show a list of bridges
2024-01-27 10:30:55.841 showmacs <bridge> show a list of mac addrs
2024-01-27 10:30:55.841 showstp <bridge> show bridge stp info
2024-01-27 10:30:55.841 stp <bridge> {on|off} turn stp on/off
2024-01-27 10:30:55.841 showmaclmt <bridge> show a mac limit of bridge
2024-01-27 10:30:55.841

with tracker 192.168.2.1#ssh_aimesh_json

IDetect: WARNING! Tracker uses depricated/invalid configuration syntax. See readme on github for correct options.192.168.2.1

without any additions:
2024-01-27 10:53:17.473 IDetect: 192.168.2.1 ====> SSH Fetching data using: /usr/sbin/wl -i eth5 assoclist
2024-01-27 10:53:17.473 /usr/sbin/wl -i eth6 assoclist
2024-01-27 10:53:17.473 /usr/sbin/wl -i wl0.1 assoclist
2024-01-27 10:53:17.473 exit
2024-01-27 10:53:17.473 IDetect: 192.168.2.1 ====> SSH not connected ... connecting
2024-01-27 10:53:17.473 IDetect: 192.168.2.1 ====> SSH start connect on port 22
2024-01-27 10:53:17.581 IDetect: 192.168.2.1 Could not be polled
2024-01-27 10:53:17.581 IDetect: 192.168.2.1 keep the clockwork ticking
2024-01-27 10:53:17.670 IDetect: 192.168.2.178 Timed poll starting like clockwork
2024-01-27 10:53:17.670 IDetect: 192.168.2.178 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_autodetect.ssh_autodetect object at 0x7fed3c1e0ee0>>
2024-01-27 10:53:17.670 IDetect: 192.168.2.178 ====> SSH Fetching data using: /usr/sbin/wl -i eth5 assoclist
2024-01-27 10:53:17.670 /usr/sbin/wl -i eth6 assoclist
2024-01-27 10:53:17.670 /usr/sbin/wl -i wl0.1 assoclist
2024-01-27 10:53:17.670 /usr/sbin/wl -i wl0.2 assoclist
2024-01-27 10:53:17.670 /usr/sbin/wl -i wl1.1 assoclist
2024-01-27 10:53:17.670 exit
2024-01-27 10:53:17.670 IDetect: 192.168.2.178 ====> SSH not connected ... connecting
2024-01-27 10:53:17.670 IDetect: 192.168.2.178 ====> SSH start connect on port 22
2024-01-27 10:53:17.808 IDetect: 192.168.2.178 Could not be polled
2024-01-27 10:53:17.808 IDetect: 192.168.2.178 keep the clockwork ticking
2024-01-27 10:53:17.993 IDetect: 192.168.2.38 Timed poll starting like clockwork
2024-01-27 10:53:17.993 IDetect: 192.168.2.38 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_autodetect.ssh_autodetect object at 0x7fed3c208dc0>>
2024-01-27 10:53:17.993 IDetect: 192.168.2.38 ====> SSH Fetching data using: /usr/sbin/wl -i eth5 assoclist
2024-01-27 10:53:17.993 /usr/sbin/wl -i eth6 assoclist
2024-01-27 10:53:17.993 /usr/sbin/wl -i wl0.1 assoclist
2024-01-27 10:53:17.993 /usr/sbin/wl -i wl0.2 assoclist
2024-01-27 10:53:17.993 /usr/sbin/wl -i wl1.1 assoclist

I used type=dummy, doesn't really help

2024-01-27 11:03:36.807 IDetect: 192.168.2.1 Timed poll starting like clockwork
2024-01-27 11:03:36.807 IDetect: 192.168.2.1 Sent RAW:this is a text with some 11:22:33:44:55:66 mac addresses 10:20:30:40:50:60. It should find 3 of them Aa-bB-CC-DD-EE-0f, even if formatted differently
2024-01-27 11:03:36.807 IDetect: Inbound data from: 192.168.2.1 containing ['11:22:33:44:55:66', '10:20:30:40:50:60', 'AA:BB:CC:DD:EE:0F']
2024-01-27 11:03:36.807 IDetect: 0 devices are present (excluding ignored devices)
2024-01-27 11:03:36.807 IDetect: 192.168.2.1 keep the clockwork ticking

[EscApe]

1. "with the tracker 192.168.2.1#ssh=brcrl"
So ssh is working! That is promising. It is returning an error message from the routers cli. That's because you just told it to run the command brctl without any command line arguments. "192.168.2.1#type=brctl" might have worked.

Did you restart Domoticz between this and the other tests?? Restarting the plugin (by updating the settings) will not work. There is a known problem with some widely used python modules and the Domoticz plugin framework. Your log will probably confirm this with an error message around the time you updated the setting.
Completely restart Domoticz after you changed any plugin setting.

2. "with tracker 192.168.2.1#ssh_aimesh_json"
The error message is correct. The "type=" is missing and the correct type name is "aimesh_json" (ssh_aimesh_json is the underlying python class that will be loaded). I know the documentation is a bit scarce on available tracker types
It should have been "192.168.2.1#type=aimesh_json"

3. "without any additions"
In a single router setup that is the correct setting. The autodiscovery should work with this router (I had a ac86u when I first developed it)
It even looks like the auto detection did something, because according to the log it already knows which command to use and which interfaces to query. I can't tell what happened in-between.

I don't see any mentions of your previous error (IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel). What has changed?

It is hard to offer you any help if you only share those pieces of the log where it is already failing. Please share full debug logs from the moment the plugin starts (beware that the Domoticz logs is not always in chronological order!). Even better would be a full log from the moment Domoticz starts. If you don't want to share it in the forum then share it in a pm.

[hjzwiers]

Nothing has changed, the message is still there. (IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel)

I am running 192.168.2.1#type=aimesh_json I think this is the one I need for Asus AI Mesh routers (as I said I have three)

I'd love to share the logging with you, if I can find it .......

[EscApe]

Thanks for sharing the log in pm. It shows two errors, but only one is relevant.

As far as I can tell we can ignore this IndexError, because it seems te be an error in the paramiko error handling. Comparable to (or even the same as) https://github.com/paramiko/paramiko/issues/20

Code: Select all

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.9/dist-packages/paramiko/transport.py", line 2254, in run
emsg = "{} ({:d})".format(e.args[1], e.args[0])
IndexError: tuple index out of range

The real error is

Code: Select all

Exception in thread Thread-2:
Traceback (most recent call last):
File "/usr/local/lib/python3.9/dist-packages/paramiko/transport.py", line 2159, in run
ptype, m = self.packetizer.read_message()
File "/usr/local/lib/python3.9/dist-packages/paramiko/packet.py", line 463, in read_message
header = self.read_all(self.__block_size_in, check_rekey=True)
File "/usr/local/lib/python3.9/dist-packages/paramiko/packet.py", line 308, in read_all
x = self.__socket.recv(n)
socket.timeout: timed out

So, still a time-out...

To further diagnose you could try the same code as the plugin in python directly. To do so, run the code below line-by-line and see what is does (change the credentials). Make sure you run it trom exactly the same environment that is also running Domoticz.

Code: Select all

import paramiko
client = paramiko.SSHClient()
client.set_missing_host_key_policy(paramiko.AutoAddPolicy())
client.connect("192.168.2.1", port="22", username="<<username>>", password="<<mypw>>", timeout=5)
stdin, stdout, stderr = client.exec_command("ls -al /", timeout=5)
print(stdout.read().decode("utf-8"))

Somehow paramiko is not able to connect to your router. The above code gives you the opportunity to try different timeout settings. You can also try different authentication methods by replacing the client.connect line with the options below.

To use key based authentication just omit the password argument (completely). Only works if keys are setup correctly.

Code: Select all

client.connect("192.168.2.1", port="22", username="<<username>>", timeout=5)

Or specify a keyfile if you want a specific one:

Code: Select all

rsa_key=paramiko.RSAKey.from_private_key_file(<<keyfile_fullpath>>)
client.connect("192.168.2.1", port="22", username="<<username>>", pkey=rsa_key, timeout=5)

I dug up an old ac68u (no longer have the ac86u) and build a test setup to try and reproduce your problem. I can't. The plugin is working just fine. Both auto-detection (for single router) and aimesh queries work as expected in this setup. So I am pretty confident the issue is no with the plug in itself. That doesn't mean you are doing anything wrong. This could be anything. Besides the possible causes I mentioned earlier it could also be a messed up python install or python module, or a firmware difference in the ac86u. Key based authentication can be a pain te setup, so that's something to triple check. What works for one userprofile in a python (virtual) environment does not necessarily work in the environment that Domoticz is run from. Hopefully the python code will help you find the cause.

My (test) ac68u was running asuswrt merlin version 386.3_2 (tested ok) and I have upgrade it to 386.12_4 (tested ok). I have not tested Asus stock firmware. There might be a difference in the stock firmware that makes the ssh session fail, but I don't hink that is very likely.
The fact that you where seeing connection attempts in the log on the router does not mean they where successful. Maybe there is something useful in the routers system log? Are the Asus SSH settings correct (e.g. do they allow password based login)?

[hjzwiers]

I did the check on paramiko:

>>> import paramiko
>>> client = paramiko.SSHClient()
>>> client.set_missing_host_key_policy(paramiko.AutoAddPolicy())
>>> client.connect("192.168.2.1", port="22", username="HJZ", password="secret", timeout=5)
>>> stdin, stdout, stderr = client.exec_command("ls -al /", timeout=5)
>>> print(stdout.read().decode("utf-8"))
drwxr-xr-x 20 HJZ root 1840 Nov 22 05:04 .
drwxr-xr-x 20 HJZ root 1840 Nov 22 05:04 ..
-rw-rw-r-- 1 HJZ root 0 Nov 22 05:04 .init_enable_core
drwxr-xr-x 2 HJZ root 8208 Nov 22 05:04 bin
drwxr-xr-x 4 HJZ root 0 Jan 1 1970 bootfs
drwxr-xr-x 2 HJZ root 160 Nov 22 05:03 cifs1
drwxr-xr-x 2 HJZ root 160 Nov 22 05:03 cifs2
drwxr-xr-x 3 HJZ root 0 Jan 1 1970 data
lrwxrwxrwx 1 HJZ root 16 Nov 22 05:04 debug -> sys/kernel/debug
drwxr-xr-x 5 HJZ root 3380 Jan 28 09:58 dev
lrwxrwxrwx 1 HJZ root 7 Nov 22 05:03 etc -> tmp/etc
lrwxrwxrwx 1 HJZ root 8 Nov 22 05:03 home -> tmp/home
drwxr-xr-x 18 HJZ root 0 Jan 28 10:31 jffs
drwxrwxr-x 4 HJZ root 3952 Nov 22 05:04 lib
lrwxrwxrwx 1 HJZ root 9 Nov 22 05:03 media -> tmp/media
drwxr-xr-x 2 HJZ root 160 Nov 22 05:03 mmc
lrwxrwxrwx 1 HJZ root 7 Nov 22 05:03 mnt -> tmp/mnt
lrwxrwxrwx 1 HJZ root 7 Nov 22 05:03 opt -> tmp/opt
dr-xr-xr-x 152 HJZ root 0 Jan 1 1970 proc
drwxr-xr-x 8 HJZ root 2544 Nov 22 05:03 rom
lrwxrwxrwx 1 HJZ root 13 Nov 22 05:03 root -> tmp/home/root
drwxr-xr-x 2 HJZ root 12872 Nov 22 05:03 sbin
dr-xr-xr-x 12 HJZ root 0 Jan 1 1970 sys
drwxr-xr-x 2 HJZ root 160 Nov 22 05:03 sysroot
drwxrwxrwx 22 HJZ root 1840 Jan 28 10:31 tmp
drwxr-xr-x 10 HJZ root 816 Nov 22 05:03 usr
drwxrwxrwt 19 HJZ root 540 Jan 28 10:12 var
drwxrwxr-x 18 HJZ root 29928 Nov 22 05:03 www

Is this what you were expecting?

I also changed to merlin, but no difference. I can also connect to the router from then NUC where domoticz is running without password, and connect with for example: wl -i eth6 assoclist. That all seems ok.

I did run the Beta once, can that have anything to do with the problems I have?

[EscApe]

Sorry, my test results were with the beta. I just retested with the 2.4 version, password based authentication and tracker config: "192.168.2.1#type=aimesh_json". Still works. As expected, since the beta is also back to using paramiko.

Switching between versions 2.4 and 2.5(the beta) should not lead to issues like this... but then again, something unexpected is happening so who knows? I have switched back and forth many times and the only (known) issues is that the Domoticz devices must be deleted when switching (because the Domoticzex device handling is the biggest change in the beta).

I'm running out of ideas to check.. Maybe:

1. ... the paramiko "time-out" error message is misleading and it is actualy an authentication issue(?) Have you tried password based? Have you tried deleting (or temporarily moving) the ssh keys on the Domoticz host to be sure it is not still trying key based authentication?

2. ... there is a difference (you are not aware of) between the environment that is running Domoticz and the cli you tried the python code on(?) Because that test was successful. Maybe you can describe your setup and share a system log from the router?

3. ... it really times out, but not always(?) That would explain why in one of your previous logs the auto-detection had worked, but the polling failed. You could experiment with even lower timeouts in the little testscript to see where it fails. These tasks should take milliseconds, so if they occasionally take much longer, there might be an issue there. I think this is unlikely, but can rule nothing out.