Python plugin: Presence detection from wireless router

[hjzwiers]

I tried running the beta again .... and it worked after deleting the previous devices.

It is working: only with the logging on! and it still gets "Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel."

Setting the polling time to 30 seconds with a grace period of 120 seconds seems to work.

I don't know why I am getting the errors I see, its strange as the rest seems to work. Maybe ther is an interaction between the beta and the previuos setup?

tested again without the logging on:

2024-01-28 14:10:34.739 IDetect: 192.168.2.1 Could not be polled
2024-01-28 14:10:34.739 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-28 14:10:34.739 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.

I did take your actions in account, but can not see how the router would be effecting the results. I did to those test on the same platfom.

[EscApe]

I tried running the beta again .... and it worked after deleting the previous devices.

It is working: only with the logging on! and it still gets "Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel."

Strange that it would work with those error messages. Are you sure? Or did it just work once or twice and then fail?

"Interaction" between the old and the new version seems unlikely, but if you only renamed the old plugin directory and installed another next to it then Domoticz cannot tell them apart. Make sure you completely delete the old directory before you git clone the new one.

Or are you running several Domoticz instances at the same time on the same machine?

You wrote: "I did to those test on the same platfom".
What do you mean by "platform"? On the same linux host there can be different environments for different users. The environment can even depend on whether a task was started from the cli, by init.d or by systemd. Python can have a virtual environment in which a different version of paramiko is installed. You could be running Domoticz inside a docker container, which is a completely separate environment. etc etc. All on the same machine.

Maybe this would be a useful test:
1. Stop the domoticz service.
2. (optionally) Backup the domoticz.db just to be sure.
3. Do the python test again to verify it still works
4. Start Domoticz from the same command line instead of restarting the service
5. See if that makes a difference...

I'm just guessing and offering possible tests because it just doesn't make sense to me and I don't know your exact setup.

[hjzwiers]

I'm running python3:

>>> 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 16:34 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 153 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 16:34 tmp
drwxr-xr-x 10 HJZ root 816 Nov 22 05:03 usr
drwxrwxrwt 19 HJZ root 540 Jan 28 16:34 var
drwxrwxr-x 18 HJZ root 29928 Nov 22 05:03 www

I guess you call this running fine

I don't know what you mean with:
4. Start Domoticz from the same command line instead of restarting the service

I'm running domoticz on a sigle Nuc. In docker:
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
ae11948e77d5 trafex/nefiteasy-http-server "docker-entrypoint.s…" 2 days ago Up 2 days 0.0.0.0:3000->3000/tcp great_vaughan
3617e17f1980 eclipse-mosquitto:latest "/docker-entrypoint.…" 3 weeks ago Up 2 days 0.0.0.0:1883->1883/tcp, 0.0.0.0:9001->9001/tcp myMosquitto
dffea7399c62 zwavejs/zwave-js-ui:latest "node server/bin/www" 3 weeks ago Up 2 days 0.0.0.0:3001->3001/tcp, 0.0.0.0:8091->8091/tcp zwave-js-ui

So I have domoticz and the plugins running as "normal" I have a second plug as you may have seen for the monitoring of solar energy over TCP (SolarEdge ModbusTCP)

When I installed the beta I first removed the iDetct with: sudo rm -r iDetect
Then I install the new version and restart domoticz (not the total NUC).

Again I find it strange that the beta iDetct only runs with logging on ....

[EscApe]

Did you do the python test from the command line of the nuc or from within the running docker container? The docker container is a separate environment, so the test will tell you nothing if you only run it from the normal cli.

To get a shell in the running docker container you first need to get the container id by running

Code: Select all

docker ps -a

and then run

Code: Select all

docker exec -it 9ff4b32c336a sh

(use the previously found ID instead of 9ff4b32c336a)
Run the python test from there to make sure it's working. Best to try it several times because the plugin seems to do something sometimes.

Your list of running docker containers does not show a Domoticz container.
Are you using the official docker image (domoticz/domoticz:stable on docker hub)?
How did you install the additional modules, like paramiko? Adding it to a docker file can be tricky. Using customstart.sh As described on https://www.domoticz.com/wiki/Docker works well for me.

My customstart.sh looks like this

#!/bin/bash

if [ -f /opt/domoticz/FIRSTRUN ]; then
echo 'Domoticz container already prepped'
else
echo 'Preparing Domoticz container for FIRSTRUN'
echo 'installing python modules'
pip install cryptography setuptools requests parallel-ssh paramiko motionblinds python_picnic_api paho-mqtt gTTS pychromecast hwmon fritzconnection
echo 'updating linux packages'
apt-get -qq update
echo 'installing linux packages'
apt-get install -y \
iputils-ping \
nano
echo 'creating FIRSTRUN file so script does not run again on container start'
touch /opt/domoticz/FIRSTRUN
cd /opt/domoticz || return
fi

My production container uses host networking, but the test container is using a bridged network, so that should not make a difference.
I do Have NET_ADMIN capabilities enabled, but I think that was for something else, not for the plugin. You could try if turning it on makes a difference.

[hjzwiers]

I only run the listed apps from a container.

Domoticz is running from the normal directory:
home/hjz/domoticz
and the plugins
home/hjz/domoticz/plugins

[hjzwiers]

I'm running iDetect with the following settings: 192.168.2.1#type=aimesh_json, 30 seconds polling and a grace period of 2 minutes.

Every 30 seconds I get the following:

2024-01-29 08:36:29.043 IDetect: 192.168.2.1 Timed poll starting like clockwork. 3 threads active (including me)
2024-01-29 08:36:29.044 IDetect: 192.168.2.1 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_aimesh_json.ssh_aimesh_json object at 0x7f4d643eba90>>
2024-01-29 08:36:29.044 IDetect: 192.168.2.1 ====> SSH Fetching data using: cat /tmp/clientlist.json
2024-01-29 08:36:29.057 IDetect: 192.168.2.1 ====> SSH returned (decoded):{"24:4B:FE:BE:45:78":{"5G":{"54:60:09:7B:BF:C0":{"ip":"192.168.2.84","rssi":"-62"}}},"B0:6E:BF:64:76:D8":{"2G":{"E4:5F:01:4A:56:71":{"ip":"192.168.2.101","rssi":"-59"},"68:A4:0E:13:BD:A8":{"ip":"192.168.2.243","rssi":"-53"}},"2G_1":{"38:5B:44:AA:80:C6":{"ip":"192.168.2.250","rssi":"-28"},"EC:94:CB:58:64:54":{"ip":"192.168.2.223","rssi":"-52"},"00:09:B0:1C:10:5B":{"ip":"192.168.2.200","rssi":"-55"}},"wired_mac":{"B0:6E:BF:63:58:70":{"ip":"192.168.2.178"},"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100"},"00:60:34:16:4A:91":{"ip":"192.168.2.9"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224"},"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219"},"84:C3:E8:0B:C6:9A":{"ip":"192.168.2.103"},"54:60:09:7B:BF:C0":{"ip":"192.168.2.84"},"AC:1F:6B:D3:7E:25":{"ip":"192.168.2.3"},"AC:1F:6B:D3:84:6C":{"ip":"192.168.2.4"},"24:4B:FE:BE:45:78":{"ip":"192.168.2.38"},"1C:69:7A:AC:0E:86":{"ip":"192.168.2.71"},"DE:54:75:CB:20:59":{"ip":"192.168.2.220"}}},"B0:6E:BF:63:58:70":{"2G":{"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100","rssi":"-41"}},"2G_2":{"B0:4A:39:85:0E:94":{"ip":"192.168.2.225","rssi":"-52"},"00:60:34:16:4A:91":{"ip":"192.168.2.9","rssi":"-60"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224","rssi":"-74"}},"5G":{"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56","rssi":"-60"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2","rssi":"-42"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219","rssi":"-59"},"3E:23:42:76:D6:5B":{"ip":"192.168.2.60","rssi":"-48"}}}}
2024-01-29 08:36:29.057 IDetect: 192.168.2.1 ====> SSH session took 13 milliseconds.
2024-01-29 08:36:29.057 IDetect: 192.168.2.1 Sent RAW:{"24:4B:FE:BE:45:78":{"5G":{"54:60:09:7B:BF:C0":{"ip":"192.168.2.84","rssi":"-62"}}},"B0:6E:BF:64:76:D8":{"2G":{"E4:5F:01:4A:56:71":{"ip":"192.168.2.101","rssi":"-59"},"68:A4:0E:13:BD:A8":{"ip":"192.168.2.243","rssi":"-53"}},"2G_1":{"38:5B:44:AA:80:C6":{"ip":"192.168.2.250","rssi":"-28"},"EC:94:CB:58:64:54":{"ip":"192.168.2.223","rssi":"-52"},"00:09:B0:1C:10:5B":{"ip":"192.168.2.200","rssi":"-55"}},"wired_mac":{"B0:6E:BF:63:58:70":{"ip":"192.168.2.178"},"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100"},"00:60:34:16:4A:91":{"ip":"192.168.2.9"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224"},"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219"},"84:C3:E8:0B:C6:9A":{"ip":"192.168.2.103"},"54:60:09:7B:BF:C0":{"ip":"192.168.2.84"},"AC:1F:6B:D3:7E:25":{"ip":"192.168.2.3"},"AC:1F:6B:D3:84:6C":{"ip":"192.168.2.4"},"24:4B:FE:BE:45:78":{"ip":"192.168.2.38"},"1C:69:7A:AC:0E:86":{"ip":"192.168.2.71"},"DE:54:75:CB:20:59":{"ip":"192.168.2.220"}}},"B0:6E:BF:63:58:70":{"2G":{"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100","rssi":"-41"}},"2G_2":{"B0:4A:39:85:0E:94":{"ip":"192.168.2.225","rssi":"-52"},"00:60:34:16:4A:91":{"ip":"192.168.2.9","rssi":"-60"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224","rssi":"-74"}},"5G":{"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56","rssi":"-60"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2","rssi":"-42"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219","rssi":"-59"},"3E:23:42:76:D6:5B":{"ip":"192.168.2.60","rssi":"-48"}}}}
2024-01-29 08:36:29.057 IDetect: Inbound data from: 192.168.2.1 containing ['24:4B:FE:BE:45:78', '54:60:09:7B:BF:C0', 'B0:6E:BF:64:76:D8', 'E4:5F:01:4A:56:71', '68:A4:0E:13:BD:A8', '38:5B:44:AA:80:C6', 'EC:94:CB:58:64:54', '00:09:B0:1C:10:5B', 'B0:6E:BF:63:58:70', 'B0:E4:D5:A3:DC:66', '00:60:34:16:4A:91', '2C:9E:FC:93:A0:DA', '9E:18:5D:BB:53:A6', '1C:87:2C:B8:2A:66', 'EE:B5:2D:2F:7E:50', '84:C3:E8:0B:C6:9A', '54:60:09:7B:BF:C0', 'AC:1F:6B:D3:7E:25', 'AC:1F:6B:D3:84:6C', '24:4B:FE:BE:45:78', '1C:69:7A:AC:0E:86', 'DE:54:75:CB:20:59', 'B0:6E:BF:63:58:70', 'B0:E4:D5:A3:DC:66', 'B0:4A:39:85:0E:94', '00:60:34:16:4A:91', '2C:9E:FC:93:A0:DA', '9E:18:5D:BB:53:A6', '1C:87:2C:B8:2A:66', 'EE:B5:2D:2F:7E:50', '3E:23:42:76:D6:5B']
2024-01-29 08:36:29.057 IDetect: 2 devices are present (excluding ignored devices)

and then evey 10 seconds:

2024-01-29 08:39:08.072 IDetect: onHeartbeat called
2024-01-29 08:39:08.072 IDetect: 2 devices are present (excluding ignored devices)

I am not getting the error at the moment, but I think that is just luck.

[hjzwiers]

After a restart the error is coming again. It is functioning properly.

2024-01-29 11:33:11.884 IDetect: 192.168.2.1 ====> SSH tried for 12 milliseconds.
2024-01-29 11:33:11.884 IDetect: 192.168.2.1 Could not be polled
2024-01-29 11:33:11.884 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-29 11:33:11.884 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.

But now I have seen that it runs without error also .......... timing within Domoticz?

[EscApe]

After a restart the error is coming again. It is functioning properly.

2024-01-29 11:33:11.884 IDetect: 192.168.2.1 ====> SSH tried for 12 milliseconds.
2024-01-29 11:33:11.884 IDetect: 192.168.2.1 Could not be polled
2024-01-29 11:33:11.884 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-29 11:33:11.884 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.

But now I have seen that it runs without error also .......... timing within Domoticz?

Your log from this morning is exactly what you should see, but after a Domoticz restart the error messages return. I don’t understand how it can still work while throwing time out errors. Or does the poll only work sometimes? As long as it succeeds once within the grace period it would appear to be working normally. You should be able to tell from a full (debug) log.
In that case it might be an actual timeout. Maybe the router, nuc or network have some kind of congestion / utilization peaks.
What happens when you reboot the entire nuc?

You could also try and experiment with the timeout values is ssh_tracker.py.

[hjzwiers]

Where can I find the timeout?

[EscApe]

Where can I find the timeout?

They are hard coded in ssh_tracker.py. Just search for timeout in the file.

Have you tried if resetting the nuc has a different effect than only restarting Domoticz? Since the plug-in first worked and failed after a Domoticz restart, it might be a clue if that is reproducible.

[hjzwiers]

I increased the timeout in ssh_tracker from 5 --> 10 and 3 --> 6.

def getfromssh(self, tracker_cli, alltimeout=10, sshtimeout=6):

Same result:
2024-01-30 09:44:42.269 IDetect: 192.168.2.1 Timed poll starting like clockwork. 2 threads active (including me)
2024-01-30 09:44:42.269 IDetect: 192.168.2.1 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_aimesh_json.ssh_aimesh_json object at 0x7f99dc62c940>>
2024-01-30 09:44:42.270 IDetect: 192.168.2.1 ====> SSH Fetching data using: cat /tmp/clientlist.json
2024-01-30 09:44:42.270 IDetect: 192.168.2.1 ====> SSH not connected ... connecting
2024-01-30 09:44:42.270 IDetect: 192.168.2.1 ====> SSHClient start connect on port 22
2024-01-30 09:44:42.405 IDetect: 192.168.2.1 ====> SSH returned (decoded):{"B0:6E:BF:64:76:D8":{"2G":{"E4:5F:01:4A:56:71":{"ip":"192.168.2.101","rssi":"-52"},"68:A4:0E:13:BD:A8":{"ip":"192.168.2.243","rssi":"-52"}},"2G_1":{"38:5B:44:AA:80:C6":{"ip":"192.168.2.250","rssi":"-26"},"EC:94:CB:58:64:54":{"ip":"192.168.2.223","rssi":"-50"},"00:09:B0:1C:10:5B":{"ip":"192.168.2.200","rssi":"-56"}},"5G":{"62:67:0F:BD:65:B4":{"ip":"192.168.2.24","rssi":"-86"}},"wired_mac":{"3E:23:42:76:D6:5B":{"ip":"192.168.2.60"},"B0:6E:BF:63:58:70":{"ip":"192.168.2.178"},"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100"},"B0:4A:39:85:0E:94":{"ip":"192.168.2.225"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224"},"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2"},"62:DE:04:2A:41:92":{"ip":"192.168.2.174"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219"},"84:D6:C5:3E:E2:8C":{"ip":"192.168.2.185"},"84:C3:E8:0B:C6:9A":{"ip":"192.168.2.103"},"54:60:09:7B:BF:C0":{"ip":"192.168.2.84"},"AC:1F:6B:D3:7E:25":{"ip":"192.168.2.3"},"AC:1F:6B:D3:84:6C":{"ip":"192.168.2.4"},"24:4B:FE:BE:45:78":{"ip":"192.168.2.38"},"1C:69:7A:AC:0E:86":{"ip":"192.168.2.71"},"DE:54:75:CB:20:59":{"ip":"192.168.2.220"}}},"24:4B:FE:BE:45:78":{"5G":{"54:60:09:7B:BF:C0":{"ip":"192.168.2.84","rssi":"-61"}}},"B0:6E:BF:63:58:70":{"2G":{"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100","rssi":"-43"}},"2G_2":{"B0:4A:39:85:0E:94":{"ip":"192.168.2.225","rssi":"-53"},"00:60:34:16:4A:91":{"ip":"192.168.2.9","rssi":"-61"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224","rssi":"-70"}},"5G":{"62:DE:04:2A:41:92":{"ip":"192.168.2.174","rssi":"-59"},"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56","rssi":"-68"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2","rssi":"-45"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219","rssi":"-52"},"3E:23:42:76:D6:5B":{"ip":"192.168.2.60","rssi":"-52"}}}}
2024-01-30 09:44:42.405 IDetect: 192.168.2.1 ====> SSH session took 135 milliseconds.
2024-01-30 09:44:42.406 IDetect: 192.168.2.1 Sent RAW:{"B0:6E:BF:64:76:D8":{"2G":{"E4:5F:01:4A:56:71":{"ip":"192.168.2.101","rssi":"-52"},"68:A4:0E:13:BD:A8":{"ip":"192.168.2.243","rssi":"-52"}},"2G_1":{"38:5B:44:AA:80:C6":{"ip":"192.168.2.250","rssi":"-26"},"EC:94:CB:58:64:54":{"ip":"192.168.2.223","rssi":"-50"},"00:09:B0:1C:10:5B":{"ip":"192.168.2.200","rssi":"-56"}},"5G":{"62:67:0F:BD:65:B4":{"ip":"192.168.2.24","rssi":"-86"}},"wired_mac":{"3E:23:42:76:D6:5B":{"ip":"192.168.2.60"},"B0:6E:BF:63:58:70":{"ip":"192.168.2.178"},"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100"},"B0:4A:39:85:0E:94":{"ip":"192.168.2.225"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224"},"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2"},"62:DE:04:2A:41:92":{"ip":"192.168.2.174"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219"},"84:D6:C5:3E:E2:8C":{"ip":"192.168.2.185"},"84:C3:E8:0B:C6:9A":{"ip":"192.168.2.103"},"54:60:09:7B:BF:C0":{"ip":"192.168.2.84"},"AC:1F:6B:D3:7E:25":{"ip":"192.168.2.3"},"AC:1F:6B:D3:84:6C":{"ip":"192.168.2.4"},"24:4B:FE:BE:45:78":{"ip":"192.168.2.38"},"1C:69:7A:AC:0E:86":{"ip":"192.168.2.71"},"DE:54:75:CB:20:59":{"ip":"192.168.2.220"}}},"24:4B:FE:BE:45:78":{"5G":{"54:60:09:7B:BF:C0":{"ip":"192.168.2.84","rssi":"-61"}}},"B0:6E:BF:63:58:70":{"2G":{"B0:E4:D5:A3:DC:66":{"ip":"192.168.2.100","rssi":"-43"}},"2G_2":{"B0:4A:39:85:0E:94":{"ip":"192.168.2.225","rssi":"-53"},"00:60:34:16:4A:91":{"ip":"192.168.2.9","rssi":"-61"},"2C:9E:FC:93:A0:DA":{"ip":"192.168.2.224","rssi":"-70"}},"5G":{"62:DE:04:2A:41:92":{"ip":"192.168.2.174","rssi":"-59"},"9E:18:5D:BB:53:A6":{"ip":"192.168.2.56","rssi":"-68"},"1C:87:2C:B8:2A:66":{"ip":"192.168.2.2","rssi":"-45"},"EE:B5:2D:2F:7E:50":{"ip":"192.168.2.219","rssi":"-52"},"3E:23:42:76:D6:5B":{"ip":"192.168.2.60","rssi":"-52"}}}}
2024-01-30 09:44:42.406 IDetect: Inbound data from: 192.168.2.1 containing ['B0:6E:BF:64:76:D8', 'E4:5F:01:4A:56:71', '68:A4:0E:13:BD:A8', '38:5B:44:AA:80:C6', 'EC:94:CB:58:64:54', '00:09:B0:1C:10:5B', '62:67:0F:BD:65:B4', '3E:23:42:76:D6:5B', 'B0:6E:BF:63:58:70', 'B0:E4:D5:A3:DC:66', 'B0:4A:39:85:0E:94', '2C:9E:FC:93:A0:DA', '9E:18:5D:BB:53:A6', '1C:87:2C:B8:2A:66', '62:DE:04:2A:41:92', 'EE:B5:2D:2F:7E:50', '84:D6:C5:3E:E2:8C', '84:C3:E8:0B:C6:9A', '54:60:09:7B:BF:C0', 'AC:1F:6B:D3:7E:25', 'AC:1F:6B:D3:84:6C', '24:4B:FE:BE:45:78', '1C:69:7A:AC:0E:86', 'DE:54:75:CB:20:59', '24:4B:FE:BE:45:78', '54:60:09:7B:BF:C0', 'B0:6E:BF:63:58:70', 'B0:E4:D5:A3:DC:66', 'B0:4A:39:85:0E:94', '00:60:34:16:4A:91', '2C:9E:FC:93:A0:DA', '62:DE:04:2A:41:92', '9E:18:5D:BB:53:A6', '1C:87:2C:B8:2A:66', 'EE:B5:2D:2F:7E:50', '3E:23:42:76:D6:5B']
2024-01-30 09:44:42.406 IDetect: 3 devices are present (excluding ignored devices)
2024-01-30 09:44:42.389 Status: IDetect: 192.168.2.1 ====> SSH connection established

024-01-30 09:47:22.716 IDetect: 192.168.2.1 Timed poll starting like clockwork. 2 threads active (including me)
2024-01-30 09:47:22.716 IDetect: 192.168.2.1 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_aimesh_json.ssh_aimesh_json object at 0x7f99dc62c940>>
2024-01-30 09:47:22.716 IDetect: 192.168.2.1 ====> SSH Fetching data using: cat /tmp/clientlist.json

2024-01-30 09:47:27.730 IDetect: 192.168.2.1 ====> SSH tried for 13 milliseconds.
2024-01-30 09:47:27.730 IDetect: 192.168.2.1 Could not be polled
2024-01-30 09:47:27.730 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-30 09:47:27.730 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.

1) did I update the right timeouts?
2) I find it strange that a connection is being made while it is already there? And 192.168.2.1 Could not be polled?
3) resetting the NUC has no effect

[EscApe]

I increased the timeout in ssh_tracker from 5 --> 10 and 3 --> 6.

def getfromssh(self, tracker_cli, alltimeout=10, sshtimeout=6):

Same result:
2024-01-30 09:44:42.269 IDetect: 192.168.2.1 Timed poll starting like clockwork. 2 threads active (including me)
2024-01-30 09:44:42.269 IDetect: 192.168.2.1 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_aimesh_json.ssh_aimesh_json object at 0x7f99dc62c940>>
2024-01-30 09:44:42.270 IDetect: 192.168.2.1 ====> SSH Fetching data using: cat /tmp/clientlist.json
2024-01-30 09:44:42.270 IDetect: 192.168.2.1 ====> SSH not connected ... connecting
2024-01-30 09:44:42.270 IDetect: 192.168.2.1 ====> SSHClient start connect on port 22
2024-01-30 09:44:42.405 IDetect: 192.168.2.1 ====> SSH returned (decoded):

< snip >

2024-01-30 09:44:42.406 IDetect: 3 devices are present (excluding ignored devices)
2024-01-30 09:44:42.389 Status: IDetect: 192.168.2.1 ====> SSH connection established

024-01-30 09:47:22.716 IDetect: 192.168.2.1 Timed poll starting like clockwork. 2 threads active (including me)
2024-01-30 09:47:22.716 IDetect: 192.168.2.1 Start poll and return results to <bound method tracker.receiver_callback of <trackers.ssh_aimesh_json.ssh_aimesh_json object at 0x7f99dc62c940>>
2024-01-30 09:47:22.716 IDetect: 192.168.2.1 ====> SSH Fetching data using: cat /tmp/clientlist.json

2024-01-30 09:47:27.730 IDetect: 192.168.2.1 ====> SSH tried for 13 milliseconds.
2024-01-30 09:47:27.730 IDetect: 192.168.2.1 Could not be polled
2024-01-30 09:47:27.730 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-30 09:47:27.730 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.

1) did I update the right timeouts?
2) I find it strange that a connection is being made while it is already there? And 192.168.2.1 Could not be polled?
3) resetting the NUC has no effect

1. There is also a timeout for "self.client.exec_command". Just search for timeout and double or triple them all. It's just a test.
2. I dont know what you mean by a connection being made while it is already there. Do you mean the line that says "2024-01-30 09:44:42.389 Status: IDetect: 192.168.2.1 ====> SSH connection established". Look at the timestamp. It really occurs before the data is returned. The domoticz log is not always in chronological order.
3. Too bad .. so we have no new clues. I cannot reproduce the problem and don't have the hardware to a build a identical setup.

I will get back to you if I do think of something, but for now I have nothing new to offer.

[hjzwiers]

I changed the alltimeout to 100, sshtimeout to 60 and the timeout of self.client.exec_command to 100 ms.

def getfromssh(self, tracker_cli, alltimeout=100, sshtimeout=60):
DomoticzEx.Debug(self.tracker_ip + " ====> SSH Fetching data using: " + tracker_cli)
starttime=datetime.now()
if not self.connected:
DomoticzEx.Debug(self.tracker_ip + ' ====> SSH not connected ... connecting')
self.ssh_connect()
if not self.connected:
return False, ''
try:
stdin, stdout, stderr = self.client.exec_command(tracker_cli, timeout=100)
ssh_output = stdout.read().decode("utf-8")
ssh_error = stderr.read().decode("utf-8")
if ssh_error != '':
DomoticzEx.Error(self.tracker_ip + ' ====> SSH returned error:' + ssh_error)
DomoticzEx.Debug(self.tracker_ip + ' ====> SSH returned (decoded):' + ssh_output)
except Exception as e:
DomoticzEx.Error(self.tracker_ip + ' ====> SSH failed with exception: ' + str(e))
DomoticzEx.Debug(self.tracker_ip + " ====> SSH tried for " + str((datetime.now()-starttime).microseconds//1000) + " milliseconds.")
try:

2024-01-31 12:29:37.257 IDetect: 192.168.2.1 ====> SSH tried for 48 milliseconds.
2024-01-31 12:29:37.257 IDetect: 192.168.2.1 Could not be polled
2024-01-31 12:29:37.257 Status: IDetect: 192.168.2.1 ====> SSH resetting connection
2024-01-31 12:29:37.257 Error: IDetect: 192.168.2.1 ====> SSH failed with exception: Timeout opening channel.

The "Could not be polled increased to 48 ms, 55ms, but is still lower then the timeouts, and increased from the previous run (was 13)

Also the polling is wrong the timing is 2:50 and the devices are off and then at 3:20 minutes it does a full scan again and finds the two devices. (My polling 30 seconds) and grace periods (2 min), and every 10s it confirms the results.

Anyway it did not help.

[hjzwiers]

I reset everything by deleting the previous iDetect and installing it with: sudo git clone -b DomoticzEx-based-beta https://github.com/d-EScape/Domoticz_iDetect.git iDetect

guess what, no errors ......... and I see that the frequency of logging with all the data from the router has increased to every 30 seconds.

There is still something fishy in the beta lol

I will leave it this way for now, thanks for all the help.

[EscApe]

I reset everything by deleting the previous iDetect and installing it with: sudo git clone -b DomoticzEx-based-beta https://github.com/d-EScape/Domoticz_iDetect.git iDetect

guess what, no errors ......... and I see that the frequency of logging with all the data from the router has increased to every 30 seconds.

There is still something fishy in the beta lol

I will leave it this way for now, thanks for all the help.

That is the correct way to install it (you only need sudo if the plugin directory is owned by root).
Do I understand correctly that you reset everything and did a clean install of the beta and now it works as expected?
So what do you think is "fishy" in the beta?
If it keeps working then this confirms that the beta is working in a clean setup, so it seems something in the previous setup was causing it to fail.

Still makes me wonder what could have caused it to fail like this. Nothing really makes sense in this whole troubleshoot. Not even the solution. The beta uses the same ssh approach as the previous version and you tried clean installs of the plugin before.

But ... finding something like this without access to the system is next to impossible, so lets just be glad you got it working

[hjzwiers]

Well what is fishy is that I did this before.... It seems very dependent on the reset, also that you need to reboot after the change of any parameters.

Any I will keep watching it for a while, and if anything happens do the reset lol, I don't dare turn the logging off.

[hjzwiers]

The error returned, after quite a number of time restarting and trouble shooting of another error.

I then simply deleted the iDetect and reinstalled the app and it is running again without error. And it all worked again. That is what I call strange.

[EscApe]

The error returned, after quite a number of time restarting and trouble shooting of another error.

I then simply deleted the iDetect and reinstalled the app and it is running again without error. And it all worked again. That is what I call strange.

Very strange indeed. Nothing is stored or changed in the plugins directory.

[Kubra]

I am using iDetect for quite some time now without any problems. But last few months I get these errormessages in my log.

2024-04-14 00:03:55.867 Error: iDetect: 192.168.178.1 Fritzbox polling error: Unable to perform operation. 401 Unauthorized (ERR_NONE) 401 Unauthorized ERR_NONE Webserver Sat, 13 Apr 2024 22:03:55 GMT
2024-04-14 00:04:38.939 Error: iDetect: 192.168.178.1 Fritzbox polling error: Unable to perform operation. 401 Unauthorized (ERR_NONE) 401 Unauthorized ERR_NONE Webserver Sat, 13 Apr 2024 22:04:38 GMT
2024-04-15 00:01:06.064 Error: iDetect: 192.168.178.1 Fritzbox polling error: Unable to perform operation. 401 Unauthorized (ERR_NONE) 401 Unauthorized ERR_NONE Webserver Sun, 14 Apr 2024 22:01:06 GMT
2024-04-15 00:01:49.115 Error: iDetect: 192.168.178.1 Fritzbox polling error: Unable to perform operation. 401 Unauthorized (ERR_NONE) 401 Unauthorized ERR_NONE Webserver Sun, 14 Apr 2024 22:01:49 GMT
2024-04-16 00:03:34.653 Error: iDetect: 192.168.178.1 Fritzbox polling error: Unable to perform operation. 401 Unauthorized (ERR_NONE) 401 Unauthorized ERR_NONE Webserver Mon, 15 Apr 2024 22:03:34 GMT

As you can see it is always every 24 hours, around midnight.

I have been searching on this error but without any luck. Perhaps there is a simple solution for this. And although iDetect performs okay, I want to get rid of this errormessage.

[EscApe]

Looks like your Fritzbox is not allowing the login at these times. iDetect doesn’t do anything different around 22:00, so I would look at the Fritzbox configuration. Any maintancance (update) jobs on the Fritzbox at 22:00? Maybe some timed blocking rules?