Synchro impossible

Pour faire suite à mes problemes de synchro, voici les informations demandées

Aucun devolo n’est configuré pour PowerSaving ou Standby
Voilà tous les logs

[2023-02-28 10:17:22]INFO[devolo_cpl     ] : ==================== START ====================
[2023-02-28 10:17:22]DEBUG[devolo_cpl     ] : action: syncDevolo
[2023-02-28 10:17:22]DEBUG[selector_events] : Using selector: EpollSelector
[2023-02-28 10:17:25]INFO[devolo_cpl     ] : ===================== END =====================
[2023-02-28 10:17:26]INFO[devolo_cpl     ] : ==================== START ====================
[2023-02-28 10:17:26]DEBUG[devolo_cpl     ] : action: syncDevolo
[2023-02-28 10:17:26]DEBUG[selector_events] : Using selector: EpollSelector
[2023-02-28 10:17:29]INFO[devolo_cpl     ] : ===================== END =====================
[2023-02-28 10:17:30]INFO[devolo_cpl     ] : ==================== START ====================
[2023-02-28 10:17:30]DEBUG[devolo_cpl     ] : action: syncDevolo
[2023-02-28 10:17:30]DEBUG[selector_events] : Using selector: EpollSelector
[2023-02-28 10:17:33]INFO[devolo_cpl     ] : ===================== END =====================
[2023-02-28 10:17:16]INFO : Lancement démon
[2023-02-28 10:17:17]DEBUG : Message reçu par jeedevolo_cpl.php:
[2023-02-28 10:17:22]DEBUG :   Ajax devolo_cpl: action: syncDevolo
[2023-02-28 10:17:25]INFO : {}
[2023-02-28 10:17:26]DEBUG :   Ajax devolo_cpl: action: syncDevolo
[2023-02-28 10:17:29]INFO : {}
[2023-02-28 10:17:30]DEBUG :   Ajax devolo_cpl: action: syncDevolo
[2023-02-28 10:17:33]INFO : {}
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : ┌─Start demond
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : │ Log level      : debug
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : │ Socket port    : 34742
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : │ Socket host    : localhost
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : │ PID file       : /tmp/jeedom/devolo_cpl/daemon.pid
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : │ Apikey         : ccccNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : │ Callback       : http://127.0.0.1:80/plugins/devolo_cpl/core/php/jeedevolo_cpl.php
[2023-02-28 10:17:17]INFO[devolo_cpld    ] : └─devolo_cpl_api : 1.2.0
[2023-02-28 10:17:17]INFO[jeedom         ] : Writing PID 2316556 to /tmp/jeedom/devolo_cpl/daemon.pid
[2023-02-28 10:17:17]INFO[jeedom         ] : Init request module v2.28.2
[2023-02-28 10:17:17]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:17:17]DEBUG[connectionpool ] : http://127.0.0.1:80 "GET /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=ccceqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 200 0
[2023-02-28 10:17:17]INFO[jeedom         ] : Socket interface started
[2023-02-28 10:17:17]INFO[jeedom         ] : LoopNetServer Thread started
[2023-02-28 10:17:17]INFO[jeedom         ] : Listening on: [localhost:34742]
[2023-02-28 10:20:02]INFO[jeedom         ] : Client connected to [127.0.0.1:51992]
[2023-02-28 10:20:02]INFO[jeedom         ] : b'{"action":"getState","serial":"1807044980004447","ip":"192.168.1.22","password":"","apikey":"cccxnXtR6OiUxdksDKuUF7FachOE"}'
[2023-02-28 10:20:02]INFO[jeedom         ] : Message read from socket: b'{"action":"getState","serial":"1807044980004447","ip":"192.168.1.22","password":"","apikey":"ccc9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE"}'
[2023-02-28 10:20:02]INFO[jeedom         ] : Client disconnected from [127.0.0.1:51992]
[2023-02-28 10:20:02]INFO[jeedom         ] : Client connected to [127.0.0.1:52002]
[2023-02-28 10:20:02]INFO[jeedom         ] : b'{"action":"getState","serial":"1807044980003120","ip":"192.168.1.243","password":"","apikey":"cccbV9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE"}'
[2023-02-28 10:20:02]INFO[jeedom         ] : Message read from socket: b'{"action":"getState","serial":"1807044980003120","ip":"192.168.1.243","password":"","apikey":"cccc"}'
[2023-02-28 10:20:02]INFO[jeedom         ] : Client disconnected from [127.0.0.1:52002]
[2023-02-28 10:20:02]INFO[jeedom         ] : Client connected to [127.0.0.1:52018]
[2023-02-28 10:20:02]INFO[jeedom         ] : b'{"action":"getRates","ip":"192.168.1.22:192.168.1.243","apikey":"cccLsbV9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE"}'
[2023-02-28 10:20:02]INFO[jeedom         ] : Message read from socket: b'{"action":"getRates","ip":"192.168.1.22:192.168.1.243","apikey":"ccc0LsbV9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE"}'
[2023-02-28 10:20:02]INFO[jeedom         ] : Client disconnected from [127.0.0.1:52018]
[2023-02-28 10:20:02]DEBUG[devolo_cpld    ] : received message: {'action': 'getState', 'serial': '1807044980004447', 'ip': '192.168.1.22', 'password': '', 'apikey': 'ccccclNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE'}
[2023-02-28 10:20:02]DEBUG[selector_events] : Using selector: EpollSelector
[2023-02-28 10:20:02]INFO[devolo_cpld    ] : ============== getState ==============
[2023-02-28 10:20:02]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:02]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:02]WARNING[_logger        ] : Error with socket 12 (('127.0.0.1', 5353))): [Errno 22] Invalid argument
Traceback (most recent call last):
File "/usr/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
self._sock.sendto(data, addr)
OSError: [Errno 22] Invalid argument
[2023-02-28 10:20:05]DEBUG[device         ] : Having trouble getting _dvl-deviceapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:05]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:05]DEBUG[device         ] : Having trouble getting _dvl-plcnetapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:05]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:08]ERROR[devolo_cpld    ] : Send command to demon error : The device 192.168.1.22 did not answer.
[2023-02-28 10:20:08]INFO[jeedom         ] : Send to jeedom :  {'action': 'message', 'code': 'devNotAnswer', 'serial': '1807044980004447', 'ip': '192.168.1.22'}
[2023-02-28 10:20:08]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:20:08]DEBUG[connectionpool ] : http://127.0.0.1:80 "POST /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=cccccsbV9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 500 0
[2023-02-28 10:20:08]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:20:08]DEBUG[connectionpool ] : http://127.0.0.1:80 "POST /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=cclNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 500 0
[2023-02-28 10:20:08]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:20:08]DEBUG[connectionpool ] : http://127.0.0.1:80 "POST /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=ccNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 500 0
[2023-02-28 10:20:09]DEBUG[devolo_cpld    ] : received message: {'action': 'getState', 'serial': '1807044980003120', 'ip': '192.168.1.243', 'password': '', 'apikey': 'cccV9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE'}
[2023-02-28 10:20:09]DEBUG[selector_events] : Using selector: EpollSelector
[2023-02-28 10:20:09]INFO[devolo_cpld    ] : ============== getState ==============
[2023-02-28 10:20:09]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:09]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:09]WARNING[_logger        ] : Error with socket 17 (('127.0.0.1', 5353))): [Errno 22] Invalid argument
Traceback (most recent call last):
File "/usr/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
self._sock.sendto(data, addr)
OSError: [Errno 22] Invalid argument
[2023-02-28 10:20:12]DEBUG[device         ] : Having trouble getting _dvl-deviceapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:12]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:12]DEBUG[device         ] : Having trouble getting _dvl-plcnetapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:12]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:15]ERROR[devolo_cpld    ] : Send command to demon error : The device 192.168.1.243 did not answer.
[2023-02-28 10:20:15]INFO[jeedom         ] : Send to jeedom :  {'action': 'message', 'code': 'devNotAnswer', 'serial': '1807044980003120', 'ip': '192.168.1.243'}
[2023-02-28 10:20:15]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:20:15]DEBUG[connectionpool ] : http://127.0.0.1:80 "POST /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=ccc4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 500 0
[2023-02-28 10:20:15]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:20:15]DEBUG[connectionpool ] : http://127.0.0.1:80 "POST /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=cccDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 500 0
[2023-02-28 10:20:15]DEBUG[connectionpool ] : Starting new HTTP connection (1): 127.0.0.1:80
[2023-02-28 10:20:15]DEBUG[connectionpool ] : http://127.0.0.1:80 "POST /plugins/devolo_cpl/core/php/jeedevolo_cpl.php?apikey=cccLsbV9lNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE HTTP/1.1" 500 0
[2023-02-28 10:20:15]DEBUG[devolo_cpld    ] : received message: {'action': 'getRates', 'ip': '192.168.1.22:192.168.1.243', 'apikey': 'cccNDC4JEjvNeqwO0N58xnXtR6OiUxdksDKuUF7FachOE'}
[2023-02-28 10:20:15]DEBUG[selector_events] : Using selector: EpollSelector
[2023-02-28 10:20:15]INFO[devolo_cpld    ] : ============== getRates ==============
[2023-02-28 10:20:15]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:15]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:15]WARNING[_logger        ] : Error with socket 22 (('127.0.0.1', 5353))): [Errno 22] Invalid argument
Traceback (most recent call last):
File "/usr/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
self._sock.sendto(data, addr)
OSError: [Errno 22] Invalid argument
[2023-02-28 10:20:19]DEBUG[device         ] : Having trouble getting _dvl-deviceapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:19]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:19]DEBUG[device         ] : Having trouble getting _dvl-plcnetapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:19]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:22]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:22]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
[2023-02-28 10:20:25]DEBUG[device         ] : Having trouble getting _dvl-deviceapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:25]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
[2023-02-28 10:20:25]DEBUG[device         ] : Having trouble getting _dvl-plcnetapi._tcp.local. via unicast messages. Switching to multicast for this device.
[2023-02-28 10:20:25]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.

Le premier log me semble bien vide. N’ayant pas accès à mes Jeedom avant ce soir, il m’est difficile de faire un diagnostique plus précis pour le moment.

Peux-tu aussi me donner le résultat de la commande pip3 list?

debian@jeedom:~$ pip3 list
Package             Version
------------------- --------------
aiohttp             3.8.4
aiosignal           1.3.1
aiosqlite           0.18.0
android-backup      0.2.0
anyio               3.6.2
appdirs             1.4.4
async-timeout       4.0.2
attrs               22.2.0
beautifulsoup4      4.9.3
bellows             0.33.1
certifi             2022.12.7
cffi                1.15.1
chardet             4.0.0
charset-normalizer  3.0.1
click               8.1.3
click-log           0.4.0
coloredlogs         15.0.1
colorzero           2.0
construct           2.10.68
crccheck            1.3.0
cryptography        39.0.1
cupshelpers         1.0
dbus-python         1.2.16
devolo-plc-api      1.2.0
dicttoxml           1.7.4
distro-info         1.0
dnspython           2.0.0
enum-compat         0.0.3
enum34              1.1.10
fail2ban            0.11.2
frozenlist          1.3.3
future              0.18.3
gpg                 1.14.0-unknown
gpiozero            1.6.2
h11                 0.12.0
html5lib            1.1
httpcore            0.14.7
httplib2            0.18.1
httpx               0.21.0
huawei-lte-api      1.6.11
humanfriendly       10.0
idna                3.4
ifaddr              0.2.0
importlib-metadata  6.0.0
iotop               0.6
jsonschema          4.17.3
lxml                4.6.3
Markdown            3.3.4
multidict           6.0.4
netifaces           0.11.0
pip                 23.0.1
protobuf            3.17.3
pure-pcapy3         1.0.1
pycairo             1.16.2
pycparser           2.21
pycrypto            2.6.1
pycryptodomex       3.9.7
pycups              2.0.1
pycurl              7.43.0.6
Pygments            2.7.1
PyGObject           3.38.0
pyinotify           0.9.6
pyrsistent          0.19.3
pyserial            3.5
pyserial-asyncio    0.6
PySimpleSOAP        1.16.2
pysmbc              1.0.23
python-apt          2.2.1
python-debian       0.1.39
python-debianbts    3.1.0
pytz                2022.7.1
pyudev              0.24.0
pyusb               1.2.1
PyYAML              5.3.1
reportbug           7.10.3+deb11u1
requests            2.28.2
requests-toolbelt   0.9.1
rfc3986             1.5.0
setuptools          67.4.0
six                 1.16.0
sniffio             1.3.0
soupsieve           2.2.1
systemd-python      234
tornado             6.2
tqdm                4.64.1
tzdata              2022.7
unattended-upgrades 0.1
urllib3             1.26.14
voluptuous          0.13.1
webencodings        0.5.1
wheel               0.38.4
xmltodict           0.12.0
xmodem              0.4.6
yarl                1.4.2
yeelight            0.7.10
zeroconf            0.36.8
zha-quirks          0.0.80
zigpy               0.50.3
zigpy-deconz        0.18.1
zigpy-xbee          0.15.0
zigpy-zigate        0.9.2
zigpy-znp           0.8.2
zipp                3.15.0

Peux-tu désinstaller devolo-plc-api pour être sûr que c’est bien la version embarquée dans le plugin qui est utilisée?

Honnêtement, je ne pense pas que ce soit la cause du problème puisque tu es en Debian 11 mais j’aimerai exclure cette hypothèse.

De mon côté, je n’ai pas encore testé le plugin en Debian 11. Ton expérience sera donc utile.

Sauf imprévu, je vais faire un test ce soir sur une Debian 11 et ferai une comparaison des versions des modules python installés

Desinstall du plugin, suppression de devolo-plc-api, reinstall.
Meme chose :frowning:

C’est malheureusement pas une surprise. Mais on a éliminé une hypothèse.

Peux-tu juste confirmer que devolo-plc-api n’est pas réapparu si tu refais un pip3 list ?

Il est revenu

2eme suppression (pip3 uninstall) sans toucher au plugin. juste relance du demon → meme chose

C’est à dire? Le module est réapparu ?

Pour info:
Le plugin contient deux script python:

  1. devolo_cpld.py
  2. devolo_cpl.py

Le premier est un daemon utiliser pour lancer des commandes en asynchrone. Il envoi les commandes et, lorsqu’il reçoit un retour, il notifie le plugin. C’est la méthode qui est utilisée pour commander les leds et pour remonter les débits entre les équipements.

Le deuxième est utilisé pour les commandes synchrone. Il est utiliser par le plugin pour les découvertes (synchros). Le plugin lance le script et attend la réponse pour la traiter.

Il etait reapparu.
on doit donc voir un demon au niveau des taches en cours sur la machine

debian@jeedom:~$ sudo ps -elf | grep devolo
0 S www-data 2571923       1  0  80   0 - 69303 -      11:51 ?        00:00:06 python3 /var/www/html/plugins/devolo_cpl/resources/bin/devolo_cpld.py --loglevel debug --socketport 34741 --callback http://127.0.0.1:80/plugins/devolo_cpl/core/php/jeedevolo_cpl.php --apikey xxxQOiqNlF7tZs9K7SZ7A7kNnSQmqlD --pid /tmp/jeedom/devolo_cpl/daemon.pid
0 S debian   2637538 2634877  0  80   0 -  1565 -      12:15 pts/0    00:00:00 grep devolo

En lancant manuellement

debian@jeedom:/var/www/html/plugins/devolo_cpl/resources/bin$ sudo python3 devolo_cpl.py --getState --ip 192.168.1.22
[2023-02-28 12:21:34][WARNING][_logger        ] : Error with socket 8 (('127.0.0.1', 5353))): [Errno 22] Invalid argument
Traceback (most recent call last):
  File "/usr/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
    self._sock.sendto(data, addr)
OSError: [Errno 22] Invalid argument
Traceback (most recent call last):
  File "/var/www/html/plugins/devolo_cpl/resources/bin/devolo_cpl.py", line 171, in <module>
    asyncio.run(getState(args))
  File "/usr/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/var/www/html/plugins/devolo_cpl/resources/bin/devolo_cpl.py", line 138, in getState
    async with Device(ip=args.ip) as dpa:
  File "/var/www/html/plugins/devolo_cpl/3rdparty/devolo_plc_api-1.1.0/devolo_plc_api/device.py", line 68, in __aenter__
    await self.async_connect()
  File "/var/www/html/plugins/devolo_cpl/3rdparty/devolo_plc_api-1.1.0/devolo_plc_api/device.py", line 124, in async_connect
    raise DeviceNotFound(f"The device {self.ip} did not answer.")
devolo_plc_api.exceptions.device.DeviceNotFound: The device 192.168.1.22 did not answer.

  1. Oui, c’est normal que le deamon tourne. Il n’installe pas devolo-plc-api mais l’utilise.

  2. l’option --getState de devolo_cpl.pyest un reliquat qui n’est plus utilisé par le plugin (La fonctionnalité est offerte par le deamon devolo_cpld.py

Les warnings concernant l’adresse ip 127.0.0.1 peuvent être ignorés. Je crois qu’ils viennent du module zeroconf qui est utilisé par devolo-plc-api.

Es-tu certain que le module devolo-plc-apia bien été désinstallé ? de mémoire (je saisi pas tout car il n’y a que quelques mois que je suis passé de Perl à python) un module peut être installé plusieurs fois

  • Au niveau système si pip est exécuté avec le droit root
  • Au niveau de l’utilisateur s’il est installé avec un compte user.

Par sécurité, il faudrait peut-être faire
pip3 uninstall devolo-plc-api; sudo pip uninstall devolo-plc-api
puis
pip list; sudo pip list

debian@jeedom:/var/www/html/plugins/devolo_cpl/resources/bin$ pip list | grep devolo; sudo pip list | grep devolo
debian@jeedom:/var/www/html/plugins/devolo_cpl/resources/bin$

Hello,
J’ai effectué les opération suivantes:

  1. Démarrer ma Debian 11 qui ne tournai pas depuis longtemps
  2. Mis à jour Debian
  3. Vérifier que le module devolo-plc-apin’était pas installé
  4. Mis à jour Jeedom 4.3.2 => 4.3.15
  5. Revérifier que le module devolo-plc-apin’était pas installé
  6. Installé le plugin Devolo_cplversion beta depuis le market
  7. L’installation des dépendances a été déclenchée automatiquement
  8. Passage du niveau de log du plugin à `debug’
  9. Revérifier que le module devolo-plc-api n’était pas installé
  10. Lancer une synchro dans le plugin
    1.Tout mes Devolo sont apparus
  11. Revérifier que le module devolo-plc-api n’était pas installé

Voici le log devolo_cpl_out après la synchro:

0000|[2023-02-28 20:25:19]INFO[devolo_cpl     ] : ==================== START ====================
0001|[2023-02-28 20:25:19]DEBUG[devolo_cpl     ] : action: syncDevolo
0002|[2023-02-28 20:25:19]DEBUG[selector_events] : Using selector: EpollSelector
0003|[2023-02-28 20:25:22]DEBUG[selector_events] : Using selector: EpollSelector
0004|[2023-02-28 20:25:22]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
0005|[2023-02-28 20:25:22]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
0006|[2023-02-28 20:25:22]DEBUG[device         ] : Updating service info of _dvl-deviceapi._tcp.local. for cplbureau.local.
0007|[2023-02-28 20:25:22]WARNING[_logger        ] : Error with socket 4 (('127.0.0.1', 5353))): [Errno 22] Invalid argument
0008|Traceback (most recent call last):
0009|File "/usr/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
0010|self._sock.sendto(data, addr)
0011|OSError: [Errno 22] Invalid argument
0012|[2023-02-28 20:25:24]DEBUG[device         ] : Updating service info of _dvl-plcnetapi._tcp.local. for cplbureau.local.
0013|[2023-02-28 20:25:24]DEBUG[selector_events] : Using selector: EpollSelector
0014|[2023-02-28 20:25:24]DEBUG[plcnetapi      ] : Getting network overview.
0015|[2023-02-28 20:25:24]DEBUG[protobuf       ] : Getting from http://10.0.1.4:14791/UfiJWrPmD6WXlmwM/plcnetapi/v0/GetNetworkOverview
0016|[2023-02-28 20:25:25]DEBUG[_client        ] : HTTP Request: GET http://10.0.1.4:14791/UfiJWrPmD6WXlmwM/plcnetapi/v0/GetNetworkOverview "HTTP/1.1 200 OK"
0017|[2023-02-28 20:25:25]DEBUG[selector_events] : Using selector: EpollSelector
0018|[2023-02-28 20:25:25]DEBUG[selector_events] : Using selector: EpollSelector
0019|[2023-02-28 20:25:25]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
0020|[2023-02-28 20:25:25]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
0021|[2023-02-28 20:25:25]DEBUG[device         ] : Updating service info of _dvl-deviceapi._tcp.local. for cplcave.local.
0022|[2023-02-28 20:25:25]DEBUG[device         ] : Updating service info of _dvl-plcnetapi._tcp.local. for cplcave.local.
0023|[2023-02-28 20:25:25]DEBUG[selector_events] : Using selector: EpollSelector
0024|[2023-02-28 20:25:25]DEBUG[plcnetapi      ] : Getting network overview.
0025|[2023-02-28 20:25:25]DEBUG[protobuf       ] : Getting from http://10.0.1.6:14791/bGNuAWNknUeOddf0/plcnetapi/v0/GetNetworkOverview
0026|[2023-02-28 20:25:26]DEBUG[_client        ] : HTTP Request: GET http://10.0.1.6:14791/bGNuAWNknUeOddf0/plcnetapi/v0/GetNetworkOverview "HTTP/1.1 200 OK"
0027|[2023-02-28 20:25:26]DEBUG[selector_events] : Using selector: EpollSelector
0028|[2023-02-28 20:25:26]DEBUG[selector_events] : Using selector: EpollSelector
0029|[2023-02-28 20:25:26]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
0030|[2023-02-28 20:25:26]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
0031|[2023-02-28 20:25:26]DEBUG[device         ] : Updating service info of _dvl-deviceapi._tcp.local. for cpljeedom.local.
0032|[2023-02-28 20:25:26]DEBUG[device         ] : Updating service info of _dvl-plcnetapi._tcp.local. for cpljeedom.local.
0033|[2023-02-28 20:25:26]DEBUG[selector_events] : Using selector: EpollSelector
0034|[2023-02-28 20:25:26]DEBUG[plcnetapi      ] : Getting network overview.
0035|[2023-02-28 20:25:26]DEBUG[protobuf       ] : Getting from http://10.0.1.8:14791/a9jQPuSzHkDWxrgJ/plcnetapi/v0/GetNetworkOverview
0036|[2023-02-28 20:25:27]DEBUG[_client        ] : HTTP Request: GET http://10.0.1.8:14791/a9jQPuSzHkDWxrgJ/plcnetapi/v0/GetNetworkOverview "HTTP/1.1 200 OK"
0037|[2023-02-28 20:25:27]DEBUG[selector_events] : Using selector: EpollSelector
0038|[2023-02-28 20:25:27]DEBUG[selector_events] : Using selector: EpollSelector
0039|[2023-02-28 20:25:27]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
0040|[2023-02-28 20:25:27]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
0041|[2023-02-28 20:25:27]DEBUG[device         ] : Updating service info of _dvl-deviceapi._tcp.local. for cplsalon-4.local.
0042|[2023-02-28 20:25:27]DEBUG[device         ] : Updating service info of _dvl-plcnetapi._tcp.local. for cplsalon-4.local.
0043|[2023-02-28 20:25:27]DEBUG[selector_events] : Using selector: EpollSelector
0044|[2023-02-28 20:25:27]DEBUG[plcnetapi      ] : Getting network overview.
0045|[2023-02-28 20:25:27]DEBUG[protobuf       ] : Getting from http://10.0.1.5:14791/efe75e936564a3ee/plcnetapi/v0/GetNetworkOverview
0046|[2023-02-28 20:25:27]DEBUG[_client        ] : HTTP Request: GET http://10.0.1.5:14791/efe75e936564a3ee/plcnetapi/v0/GetNetworkOverview "HTTP/1.1 200 OK"
0047|[2023-02-28 20:25:27]DEBUG[selector_events] : Using selector: EpollSelector
0048|[2023-02-28 20:25:27]DEBUG[selector_events] : Using selector: EpollSelector
0049|[2023-02-28 20:25:28]DEBUG[device         ] : Browsing for _dvl-deviceapi._tcp.local.
0050|[2023-02-28 20:25:28]DEBUG[device         ] : Browsing for _dvl-plcnetapi._tcp.local.
0051|[2023-02-28 20:25:28]DEBUG[device         ] : Updating service info of _dvl-deviceapi._tcp.local. for cplphil.local.
0052|[2023-02-28 20:25:28]DEBUG[device         ] : Updating service info of _dvl-plcnetapi._tcp.local. for cplphil.local.
0053|[2023-02-28 20:25:28]DEBUG[selector_events] : Using selector: EpollSelector
0054|[2023-02-28 20:25:28]DEBUG[plcnetapi      ] : Getting network overview.
0055|[2023-02-28 20:25:28]DEBUG[protobuf       ] : Getting from http://10.0.1.7:14791/daf2734eef4de505/plcnetapi/v0/GetNetworkOverview
0056|[2023-02-28 20:25:28]DEBUG[_client        ] : HTTP Request: GET http://10.0.1.7:14791/daf2734eef4de505/plcnetapi/v0/GetNetworkOverview "HTTP/1.1 200 OK"
0057|[2023-02-28 20:25:28]DEBUG[selector_events] : Using selector: EpollSelector
0058|[2023-02-28 20:25:28]INFO[devolo_cpl     ] : ===================== END =====================

Et la liste des module python:

root@jeedomi43:~# pip list
Package             Version
------------------- --------------
anyio               3.6.2
certifi             2022.12.7
chardet             4.0.0
charset-normalizer  3.0.1
cupshelpers         1.0
dbus-python         1.2.16
distro-info         1.0
fail2ban            0.11.2
gpg                 1.14.0-unknown
h11                 0.12.0
httpcore            0.14.7
httplib2            0.18.1
httpx               0.21.0
idna                3.4
ifaddr              0.2.0
importlib-metadata  6.0.0
iotop               0.6
msgpack             1.0.2
pip                 23.0.1
protobuf            3.17.3
pycairo             1.16.2
pycups              2.0.1
pycurl              7.43.0.6
PyGObject           3.38.0
pyinotify           0.9.6
PySimpleSOAP        1.16.2
pysmbc              1.0.23
python-apt          2.2.1
python-debian       0.1.39
python-debianbts    3.1.0
reportbug           7.10.3+deb11u1
requests            2.25.1
rfc3986             1.5.0
setuptools          52.0.0
signalrcore         0.9.2
six                 1.16.0
sniffio             1.3.0
systemd-python      234
unattended-upgrades 0.1
urllib3             1.26.5
websocket-client    0.54.0
wheel               0.34.2
zeroconf            0.36.8
zipp                3.15.0

Je n’arrive pas à comprendre pourquoi ça ne fonctionne pas chez toi.

Désolé d’insister mais j’aimerais vraiment voir le résultat d’un ping d’un de tes Devolo depuis le serveur Jeedom. (avec au moins une vingtaine de séquences)

debian@jeedom:~$ ping 192.168.1.22
PING 192.168.1.22 (192.168.1.22) 56(84) bytes of data.
64 bytes from 192.168.1.22: icmp_seq=1 ttl=60 time=0.957 ms
64 bytes from 192.168.1.22: icmp_seq=2 ttl=60 time=0.748 ms
64 bytes from 192.168.1.22: icmp_seq=3 ttl=60 time=1.03 ms
64 bytes from 192.168.1.22: icmp_seq=4 ttl=60 time=0.925 ms
64 bytes from 192.168.1.22: icmp_seq=5 ttl=60 time=1.10 ms
64 bytes from 192.168.1.22: icmp_seq=6 ttl=60 time=0.962 ms
64 bytes from 192.168.1.22: icmp_seq=7 ttl=60 time=1.07 ms
64 bytes from 192.168.1.22: icmp_seq=8 ttl=60 time=1.34 ms
64 bytes from 192.168.1.22: icmp_seq=9 ttl=60 time=2.00 ms
64 bytes from 192.168.1.22: icmp_seq=10 ttl=60 time=0.724 ms
64 bytes from 192.168.1.22: icmp_seq=11 ttl=60 time=0.929 ms
64 bytes from 192.168.1.22: icmp_seq=12 ttl=60 time=1.09 ms
64 bytes from 192.168.1.22: icmp_seq=13 ttl=60 time=1.08 ms
64 bytes from 192.168.1.22: icmp_seq=14 ttl=60 time=18.6 ms
64 bytes from 192.168.1.22: icmp_seq=15 ttl=60 time=0.996 ms
^C
--- 192.168.1.22 ping statistics ---
15 packets transmitted, 15 received, 0% packet loss, time 14065ms
rtt min/avg/max/mdev = 0.724/2.237/18.600/4.382 ms

1 « J'aime »
debian@jeedom:~$ pip3 -V
pip 23.0.1 from /usr/local/lib/python3.9/dist-packages/pip (python 3.9)

Peut-etre une cause, la version de python.

Je me demandais si tu avais éventuellement des latences ou pertes de paquets aurai pu provoquer des timeout ou autres. Ce n’est visiblement pas le cas

Tu as vu que dans mes logs, je commence par deux fois

[2023-02-28 20:25:19]DEBUG[selector_events] : Using selector: EpollSelector

Alors que chez toi, ça s’arrête après le premier.

Je vais publier ce soir ou plus probablement demain soir une nouvelle version du plugin. Je vais ajouter des log dans le script de synchro afin de tenter dans savoir plus.

Je ne pense pas que la version de python soit en cause car j’ai fait le test hier soir avec une Debian 11 qui python 3.9.

Je risque de devoir me plonger dans le code de devolo_plc-api mais ça ne sera pas évident si je n’arrive pas à reproduire le problème.

Autre question bête: Est-ce que les firmwares de tes Devolo sont à jour?

Firmware version : magic-2-lan 7.8.0.4

Je vérifie chez moi ce soir…

chez moi, j’ai les firmware suivants:
Magic 1 Lan : 7.12.6.131 (2022-11-17)
Magic 2 Lan : 7.12.6.131 (2022-11-17)
Magic 2 WiFi 6 : 5.10.3 (2022-09-09)

Il s’agit des versions indiquées dans l’app Devolo. Mais les Magic 2 Wifi 6 indiquent la version 7.12.5.125 dans le plugin Jeedom (La version du plugin qui remonte les version de firmware n’est pas encore publiée).

Peux-tu mettre à jour au moins un de tes appareils Magic 2 Lan puis retenter une synchro ?

Bonne nouvelle: j’ai le même problème :frowning:

Situation dans la version beta du plugin:

  • Le daemon écrit en python utilise la version embarquée de devolo_plc_api qui est sélectionnée dans la page de configuration du plugin (1.1.0 ou 1.2.0).
  • Le script python qui effectue la découverte des appareils est encore hardcodé pour utiliser la version 1.1.0
    embarquée dans le plugin.

Mais ceci ne fonctionne que si le module devolo_plc_api n’est pas installé sur le serveur Debian. Si c’est le cas, c’est la version installée dans l’os qui sera utilisée prioritairement.

Version de dev que je m’apprêtai à plubier en nouvelle beta:

  • J’ai modifié le script de découverte afin qu’il utilise aussi la version sélectionnée dans la page de config
    du plugin.
  • Après avoir fait la modification, j’ai supprimé un équipement puis relancé la synchro… qui n’a pas fonctionné.
  • Le log était aussi court que chez toi:
2023-03-01 23:46:01]INFO[devolo_cpl     ] : ==================== START ====================
2023-03-01 23:46:01]DEBUG[devolo_cpl     ] : action: syncDevolo
2023-03-01 23:46:02]DEBUG[selector_events] : Using selector: EpollSelector
2023-03-01 23:46:05]INFO[devolo_cpl     ] : ===================== END =====================
  • J’ai alors sélectionné la version 1.1.0 dans la config du plugin puis relancé une synchro… qui a fonctioné

Analyse:

  • Le problème semble venir de la version 1.2.0 de devolo_plc_api. Reste à savoir si c’est dû aux
    modifications que j’ai effectué pour le rendre compatible python 3.7 ou si c’est le module d’origine
    qui a un problème.
  • Je ne peux que supposer que tu as une version 1.2.0 installée dans ta Debian car ça expliquerai que
    ton installation utilise la dernière version du module (1.2.0).
  • Il faut que je fasse un test sur ma machine virtuelle en Debian 11 avec un module 1.1.0 non modifié
    pour confirmer que le découverte fonctionne puis avec un module 1.2.0 pour confirmer que la
    découverte ne fonctionne pas.

Suite des opérations:

Si les tests montrent que le dysfonctionnement est dû à mes modifications du module, il faudra que je
trouve comment corriger ça

Sinon, il faudra:

  • Que j’ouvre une issue sur github pour signaler le problème.
  • Que je modifie les deux scripts Python pour qu’ils utilisent en priorité les modules embarqués.
  • Que je force l’utilisation du module 1.1.0 dans le script de découverte.

Je vais effectuer les tests ce jeudi ou vendredi soir et donnerai des nouvelles dès qu’il y en a.

EDIT:

Hello,
Le problème vient finalement de mon adaptation de module devolo_plc_apipour python 3.7:

J’ai dû remplacer la ligne

from importlib.metadata import PackageNotFoundError, version

par

from importlib_metadata import PackageNotFoundError, version

Bien que ces deux modules difinissent tout deux PackageNotFoundError il semble que importlib_metadata ne soit pas équivalent à importlib.metadata et qu’il perturbe la fonctionnement de devolo_plc_api.

Je trouverai une solution ce weekend…

1 « J'aime »