Problème stabilité - Githubissues

ioull commented 5 years ago

Après une certaine période, le plugin ne recois plus de nouveaux evenements : Par exemple hier dernier message recu à 21:47 :

[2018-11-03 21:41:07][DEBUG][zigate] : Received response 0x8102: b';\xd7\x82\x01\x00\x00\xff\x01\x00B\x00!\x01!\xb3\x0b\x03(\x11\x04!\xa8\x13\x05!\x07\x00\x06$\x01\x00\x00\x00\x00
!\x00\x00d\x10\x00\x0b!\x03\x00'
[2018-11-03 21:41:07][DEBUG][zigate] : RESPONSE 0x8102 - Individual Attribute Report : sequence:59, addr:d782, endpoint:1, cluster:0, attribute:65281, status:0, data_type:66, size:33, data:0121b30b0328110421a81305210700062401000000000a2100006410000b210300, rssi:108
[2018-11-03 21:41:07][DEBUG][zigate] : Dispatch ZIGATE_RESPONSE_RECEIVED
[2018-11-03 21:41:07][DEBUG][zigate] : Dispatch ZIGATE_ATTRIBUTE_UPDATED
[2018-11-03 21:41:07][DEBUG][root] : External command ZIGATE_ATTRIBUTE_UPDATED : {'zigate': <zigate.core.ZiGate object at 0x7f44ea9662b0>, 'attribute': {'endpoint': 1, 'data': '0121b30b0328110421a81305210700062401000000000a2100006410000b210300', 'cluster': 0, 'attribute': 65281, 'addr': 'd782', 'name': 'battery', 'value': 2.995, 'unit': 'V'}, 'device': Device d782 lumi.sensor_motion.aq2}
[2018-11-03 21:41:07][DEBUG][root] : Send to jeedom :  {'attribute': {'endpoint': 1, 'data': '0121b30b0328110421a81305210700062401000000000a2100006410000b210300', 'cluster': 0, 'attribute': 65281, 'addr': 'd782', 'name': 'battery', 'value': 2.995, 'unit': 'V'}, 'action': 'ZIGATE_ATTRIBUTE_UPDATED', 'device': Device d782 lumi.sensor_motion.aq2}
[2018-11-03 21:41:07][DEBUG][requests.packages.urllib3.connectionpool] : Starting new HTTP connection (1): 127.0.0.1
[2018-11-03 21:41:07][DEBUG] : Array (     [attribute] => Array         (             [endpoint] => 1             [data] => 0121b30b0328110421a81305210700062401000000000a2100006410000b210300             [cluster] => 0             [attribute] => 65281             [addr] => d782             [name] => battery             [value] => 2.995             [unit] => V         )      [action] => ZIGATE_ATTRIBUTE_UPDATED     [device] => Array         (             [info] => Array                 (                     [rssi] => 108                     [mac_capability] => 10000000                     [max_tx] => 100                     [bit_field] => 0100000000000010                     [addr] => d782                     [max_buffer] => 127                     [server_mask] => 0                     [manufacturer] => 1037                     [power_type] => 0                     [last_seen] => 2018-11-03 21:41:07                     [ieee] => 00158d0001b1cf93                     [id] => 7                     [max_rx] => 100                     [descriptor_capability] => 00000000                 )              [addr] => d782             [endpoints] => Array                 (                     [0] => Array                         (                             [in_clusters] => Array                                 (                                     [0] => 0                                     [1] => 65535                                     [2] => 1030                                     [3] => 1024                                     [4] => 1280                                     [5] => 1                                     [6] => 3                                 )                              [endpoint] => 1                             [device] => 263                             [profile] => 260                             [out_clusters] => Array                                 (                                     [0] => 0                                     [1] => 25                                 )                              [clusters] => Array                                 (                                     [0] => Array                                         (                                             [cluster] => 0                                             [attributes] => Array                                                 (                                                     [0] => Array                                                         (                                                             [name] => application_version                                                             [value] => 5                                                             [data] => 5                                                             [attribute] => 1                                                         )                                                      [1] => Array                                                         (                                                             [name] => type                                                             [value] => lumi.sensor_motion.aq2                                                             [data] => lumi.sensor_motion.aq2                                                             [attribute] => 5                                                         )                                                      [2] => Array                                                         (                                                             [data] => 0121b30b0328110421a81305210700062401000000000a2100006410000b210300                                                             [attribute] => 65281                                                             [name] => battery                                                             [value] => 2.995                                                             [unit] => V                                                         )                                                  )                                          )                                      [1] => Array                                         (                                             [cluster] => 1024                                             [attributes] => Array                                                 (                                                     [0] => Array                                                         (                                                             [data] => 28                                                             [attribute] => 0                                                             [name] => luminosity                                                             [value] => 28                                                             [unit] => lm                                                         )                                                  )                                          )                                      [2] => Array                                         (                                             [cluster] => 1030                                             [attributes] => Array                                                 (                                                     [0] => Array                                                         (                                                             [data] =>                                                              [attribute] => 0                                                             [name] => presence                                                             [value] =>                                                              [expire] => 10                                                         )                                                  )                                          )                                  )                          )                  )          )  )
[2018-11-03 21:41:07][DEBUG] : create command 1.0.65281
[2018-11-03 21:41:07][DEBUG][requests.packages.urllib3.connectionpool] : http://127.0.0.1:80 "POST /plugins/zigate/core/php/jeeZiGate.php?apikey=hHWPN5tmZPbDbHuIl8j6GSgcwR07xZrI HTTP/1.1" 200 16
[2018-11-03 21:41:07][DEBUG][root] : Jeedom reply :  {'success': True}
[2018-11-03 21:44:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 21:49:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 21:54:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 21:59:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 22:04:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 22:09:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 22:14:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 22:19:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json
[2018-11-03 22:24:06][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json

Par contre elle prends bien compte les commandes : On voit les reponses de la clef pour les versions et la non réponse de la commande off sur ma lumière philips qui s'est bien éteinte pourtant ...

[2018-11-04 09:35:10][DEBUG] : callZiGate get_version_text
[2018-11-04 09:35:10][DEBUG][root] : Message received in socket
[2018-11-04 09:35:10][DEBUG][root] : {'args': '', 'action': 'get_version_text'}
[2018-11-04 09:35:10][DEBUG][root] : {'success': True, 'result': '3.0d'}
[2018-11-04 09:35:10][DEBUG] : result callZiGate Array (     [success] => 1     [result] => 3.0d )
[2018-11-04 09:35:10][DEBUG] : callZiGate get_libversion
[2018-11-04 09:35:10][DEBUG][root] : Message received in socket
[2018-11-04 09:35:10][DEBUG][root] : {'args': '', 'action': 'get_libversion'}
[2018-11-04 09:35:10][DEBUG][root] : {'success': True, 'result': '0.20.2'}
[2018-11-04 09:35:10][DEBUG] : result callZiGate Array (     [success] => 1     [result] => 0.20.2 )
[2018-11-04 09:36:24][DEBUG] : callZiGate action_onoff Array (     [0] => 71e4     [1] => 11     [2] => 0 )
[2018-11-04 09:36:24][DEBUG][root] : Message received in socket
[2018-11-04 09:36:24][DEBUG][root] : {'args': ['71e4', 11, 0], 'action': 'action_onoff'}
[2018-11-04 09:36:24][DEBUG][zigate] : REQUEST : 0x0092 b'\x02q\xe4\x01\x0b\x00'
[2018-11-04 09:36:24][DEBUG][zigate] : Msg to send b'00920006090271e4010b00'
[2018-11-04 09:36:24][DEBUG][zigate] : Encoded Msg to send b'\x01\x02\x10\x92\x02\x10\x02\x16\x02\x19\x02\x12q\xe4\x02\x11\x02\x1b\x02\x10\x03'
[2018-11-04 09:36:24][DEBUG][zigate] : Waiting for status message for command 0x0092
[2018-11-04 09:36:27][ERROR][zigate] : No response after command 0x0092
[2018-11-04 09:36:27][DEBUG][root] : {'success': True, 'result': None}
[2018-11-04 09:36:27][DEBUG] : result callZiGate Array (     [success] => 1     [result] =>  )

Un petit redémarrage du démon et ca repart ... C'est comme si une tache de reception des messages étaient plantée ...

doudz commented 5 years ago

C'est possible mais je pense qu'on verrait un traceback dans le log. Question bête, est-ce qu'il y a eu des évènements après 21h41 et 22h24 ? s'il ne s'est rien passé, il peut être normal que rien n'est été reçu.

ioull commented 5 years ago

Si si je recois des sondes de temperatures très regulierement et les appuis sur différents boutons que j'ai généré au matin n'ont pas été pris en compte.

On Sun, Nov 4, 2018 at 2:14 PM Sébastien RAMAGE notifications@github.com wrote:

C'est possible mais je pense qu'on verrait un traceback dans le log. Question bête, est-ce qu'il y a eu des évènements après 21h41 et 22h24 ? s'il ne s'est rien passé, il peut être normal que rien n'est été reçu.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-435668648, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoPnPnJzWwzMlP2oO6c1bfUAbT0uRks5uruhSgaJpZM4YNNHs .

llaumgui commented 5 years ago

Tu es en quel version ? Il y a eu des modifications sur le daemon. Du coup fallait le relancer sinon on pouvait avoir ce genre de pb. C'est général ou c'est réglé à présent ?

ioull commented 5 years ago

Non ce n'est pas réglé ... Malgré un gros try/catch qui aurait dû éviter que la tâche réception des messages provenant de la librairie zigate ne crash. Je pense donc effectivement a un crash côté librairie zigate mais sans log :-(

Voici mes versions : Version plugin 1.1.2-b4 Version lib 0.20.2 Version firmware 3.0d

Quand tu parles de redémarrer le démon, c'est celui de jeedom ? Je le relance des que je vois que c'est crashé ...

Le mer. 7 nov. 2018 à 10:19, Guillaume Kulakowski notifications@github.com a écrit :

Tu es en quel version ? Il y a eu des modifications sur le daemon. Du coup fallait le relancer sinon on pouvait avoir ce genre de pb. C'est général ou c'est réglé à présent ?

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-436557852, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoAp9fxdqVLc1FEbWwI8YIn_oLomoks5usqWvgaJpZM4YNNHs .

doudz commented 5 years ago

C'est très ennuyeux... Tous les logs sont bien en mode debug ? Quand ça plante, est ce que tu vois une augmentation de l'utilisation du cpu?

ioull commented 5 years ago

Les logs du plugin zigate sont en mode début oui mais il y a d'autres log a mettre en debug ?

Pas d'augmentation CPU non,.

Il faudrait que je copie la librairie zigate dans le plugin et ajouter des logs dans la librairie pour voir ... Tu as une tâche qui tourne pour lire le port série j'imagine ?

Le mer. 7 nov. 2018 à 12:33, Sébastien RAMAGE notifications@github.com a écrit :

C'est très ennuyeux... Tous les logs sont bien en mode debug ? Quand ça plante, est ce que tu vois une augmentation de l'utilisation du cpu?

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-436594856, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoC0NtKV5eMPzHX48IrJsSKUIil-2ks5ussUjgaJpZM4YNNHs .

llaumgui commented 5 years ago

Maintenant que tu le dit je crois avoir déjà rencontré ça...

doudz commented 5 years ago

Il y 2 taches, une qui dialogue avec le port série et une qui traite les messages entrants ça peut être l'une ou l'autre, ou les 2...

doudz commented 5 years ago

Est-ce que c'est depuis que la librairie est passé en version 0.20 ? car cette version à apporter quelques petits bug...

llaumgui commented 5 years ago

Hier sur la sable.

llaumgui commented 5 years ago

Bonjour,

hier soir:

[2018-11-21 04:15:42][DEBUG][root] : External command ZIGATE_ATTRIBUTE_UPDATED : {'zigate': <zigate.core.ZiGate object at 0xffffa9fb1c18>, 'attribute': {'cluster': 1029, 'unit': '%', 'data': 9438, 'value': 94.38, 'attribute': 0, 'endpoint': 1, 'name': 'humidity', 'addr': '3319'}, 'device': Device 3319 lumi.weather}
Exception in thread Thread-3:
Traceback (most recent call last):
File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
self.run()
File "/usr/lib/python3.5/threading.py", line 862, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.5/dist-packages/zigate/transport.py", line 93, in listen
self.read_data(data)
File "/usr/local/lib/python3.5/dist-packages/zigate/transport.py", line 80, in read_data
threading.Thread(target=self.packet_received, args=(raw_message,)).start()
File "/usr/lib/python3.5/threading.py", line 844, in start
_start_new_thread(self._bootstrap, ())
RuntimeError: can't start new thread

Et du coup même symptome que @ioull Pour moi le problème est dans la lib ?

ioull commented 5 years ago

Ce qui est bizarre c'est que j'ai pas de stacktrace moi ... Par contre pour tester un patch, je suis champion, ca tombe environ 1 fois par jour ;-)

On Wed, Nov 21, 2018 at 8:09 AM Guillaume Kulakowski < notifications@github.com> wrote:

Bonjour,

hier soir:

[2018-11-21 04:15:42][DEBUG][root] : External command ZIGATE_ATTRIBUTE_UPDATED : {'zigate': <zigate.core.ZiGate object at 0xffffa9fb1c18>, 'attribute': {'cluster': 1029, 'unit': '%', 'data': 9438, 'value': 94.38, 'attribute': 0, 'endpoint': 1, 'name': 'humidity', 'addr': '3319'}, 'device': Device 3319 lumi.weather} Exception in thread Thread-3: Traceback (most recent call last): File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner self.run() File "/usr/lib/python3.5/threading.py", line 862, in run self._target(*self._args, **self._kwargs) File "/usr/local/lib/python3.5/dist-packages/zigate/transport.py", line 93, in listen self.read_data(data) File "/usr/local/lib/python3.5/dist-packages/zigate/transport.py", line 80, in read_data threading.Thread(target=self.packet_received, args=(raw_message,)).start() File "/usr/lib/python3.5/threading.py", line 844, in start _start_new_thread(self._bootstrap, ()) RuntimeError: can't start new thread

Et du coup même symptome que @ioull https://github.com/ioull Pour moi le problème est dans la lib ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-440560449, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoN3vKXkp8tALWaN_78R-4LzQLI2Cks5uxPwygaJpZM4YNNHs .

doudz commented 5 years ago

Le message est clair, impossible de démarrer un nouveau Thread. Cela arrive lorsqu'on atteint les limites de capacités du système. Je vais chercher de mon côté

doudz commented 5 years ago

Je viens de créer un PR pour ajouter le nom du Thread dans les logs, cela pourra permettre de voir qui génère des Thread à l'infini @ioull @llaumgui pouvez-vous tester ?

llaumgui commented 5 years ago

Oui, je sais mais j'ai rien eu a cette heure... Après ma charge et mon CPU sont pas déconnant sur ce créneau.

doudz commented 5 years ago

Eventuellement il faudrait faire un ps -othcount <PID> en indiquant le PID du démon pour voir ce qui cloche Eventuellement surveiller pendant un moment watch ps -othcount <PID>

ioull commented 5 years ago

J'ai le plugin en panne depuis 2h du mat, je peux faire des tests si vous voulez :

vinz@myjeedom:/var/www/html/plugins/zigate/resources/zigated/zigate.old$ ps
-ef |grep zigate
www-data 28062     1  0 nov.20 ?       00:12:25 /usr/bin/python3
/var/www/html/plugins/zigate/core/class/../../resources/zigated/zigated.py
--device auto --loglevel debug --apikey hHWPN5tmZPbDbHuIl8j6GSgcwR07xZrI
--pid /tmp/jeedom/zigate/daemon.pid --socket /tmp/jeedom/zigate/daemon.sock
--callback http://127.0.0.1:80/plugins/zigate/core/php/jeeZiGate.php
--sharedata 1
vinz     31199 28650  0 14:57 pts/0    00:00:00 grep zigate
vinz@myjeedom:/var/www/html/plugins/zigate/resources/zigated/zigate.old$ ps
-othcount 28062
THCNT
    6

doudz commented 5 years ago

A vérifier mais il me semble que le nombre de Thread devrait être 5 au repos

Main Thread du démon
2 pour le démon
2 pour la lib zigate

donc 6, sans doute qu'un thread en bloqué, peut-être un lock qui est coincé

llaumgui commented 5 years ago

Après je veux bien qu'a un moment il y ai un peu moins de puissance dispo, mais d'autre daemon ne plante pas...

doudz commented 5 years ago

C'est pas une question de puissance. Ya 2 pb Pour toi c'est une limite de thread atteinte , sans doute à cause d'un timer, je dois traiter le problème autrement. L'autre souci concerne un plantage , je pense à un verrou qui bloque le thread, pour le savoir il faudrait avoir les logs en debug , et vérifier le nombre de thread au repos, je pense que c'est 5 mais à vérifier

llaumgui commented 5 years ago

OK, déjà je vais passer ton PR en dev voir beta.

ioull commented 5 years ago

Je peux fournir les logs en debug complete ... Mais vous avez l'extrait dans le premier post ... Je n'ai pas d'information supplementaire même si j'ai essayé d'ajouter des logs dans la librairie et dans le plugin ...

Si vous avez une librairie plus verbeuse ou m'aiguiller dans quel thread se mettre je peux en ajouter !!!

Au repos le nombre de thread chez moi est bien 6. En ce moment en tout cas il est à 6 et je recois bien les infos de la clef.

On Thu, Nov 22, 2018 at 12:29 PM Guillaume Kulakowski < notifications@github.com> wrote:

OK, déjà je vais passer ton PR en dev voir beta.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-441001612, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoDayxTyY64s0D4KKPBVGGRo13X3Yks5uxoqsgaJpZM4YNNHs .

doudz commented 5 years ago

ok, donc au repos c'est donc 6 (j'ai oublié de compter la sauvegarde automatique) il n'y a donc rien de bloquer. @ioull tu as quel firmware ? 3.0d ou 3.0e ?

ioull commented 5 years ago

toujours en 3.0d, le plugin n'est pas encore compatible 3.0e il me semble ? Je peux faire les changements car ce n'est pas en production pour moi ;-)

On Thu, Nov 22, 2018 at 1:07 PM Sébastien RAMAGE notifications@github.com wrote:

ok, donc au repos c'est donc 6 (j'ai oublié de compter la sauvegarde automatique) il n'y a donc rien de bloquer. @ioull https://github.com/ioull tu as quel firmware ? 3.0d ou 3.0e ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-441010374, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoDXLPEqmQLcUIdc_dZ2uf_mR15k7ks5uxpNogaJpZM4YNNHs .

doudz commented 5 years ago

Pour le 3.0e il faut utiliser la lib python 0.21.2

ioull commented 5 years ago

ET pas besoin de changement dans le plugin ?

On Thu, Nov 22, 2018 at 4:05 PM Sébastien RAMAGE notifications@github.com wrote:

Pour le 3.0e il faut utiliser la lib python 0.21.2

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-441056743, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoHqkWr8JFvoGf-7IMmBsOWA0ZJu-ks5uxr0igaJpZM4YNNHs .

doudz commented 5 years ago

Non pas d'autres changements que la version de la lib zigate C'est tout l'intérêt de la lib python, elle gère le plus de choses possibles de façon à ce que l'utilisation soit simple

llaumgui commented 5 years ago

Attention: https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/blob/master/resources/zigate_version.txt Faut que je merge les PR ce we...

llaumgui commented 5 years ago

C'est mieux depuis a MAJ de la version de la lib ?

ioull commented 5 years ago

Non pas pour moi ... planté à 22h15 cette nuit :-(

On Mon, Dec 3, 2018 at 3:38 PM Guillaume Kulakowski < notifications@github.com> wrote:

C'est mieux depuis a MAJ de la version de la lib ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-443731966, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoEQdjlXKnPlRBTcibH9LRVQGxMe1ks5u1Td9gaJpZM4YNNHs .

doudz commented 5 years ago

Rien dans le log ? Tu fonctionnes sur quoi ? J'ai déjà eu ce genre de bizarrerie sur mon RPI quand la carte SD commence à mourir

ioull commented 5 years ago

Toujours rien dans les logs .... [2018-12-02 21:43:37][DEBUG] : create command 1.1027.16 [2018-12-02 21:43:37][DEBUG][requests.packages.urllib3.connectionpool] : http://127.0.0.1:80 "POST /plugins/zigate/core/php/jeeZiGate.php?apikey=hHWPN5tmZPbDbHuIl8j6GSgcwR07xZrI HTTP/1.1" 200 16 [2018-12-02 21:43:37][DEBUG][root] : Jeedom reply : {'success': True} [2018-12-02 21:45:16][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-02 21:45:16][DEBUG][zigate] : Saving persistent file [2018-12-02 21:45:16][DEBUG][zigate] : File already existing, make a backup before [2018-12-02 21:50:16][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-02 21:50:16][DEBUG][zigate] : Saving persistent file [2018-12-02 21:50:16][DEBUG][zigate] : File already existing, make a backup before [2018-12-02 21:55:16][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-02 21:55:16][DEBUG][zigate] : Saving persistent file [2018-12-02 21:55:16][DEBUG][zigate] : File already existing, make a backup before [2018-12-02 22:00:16][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-02 22:00:16][DEBUG][zigate] : Saving persistent file [2018-12-02 22:00:16][DEBUG][zigate] : File already existing, make a backup before [2018-12-02 22:05:16][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-02 22:05:16][DEBUG][zigate] : Saving persistent file [2018-12-02 22:05:16][DEBUG][zigate] : File already existing, make a backup before [2018-12-02 22:10:16][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-02 22:10:16][DEBUG][zigate] : Saving persistent file [2018-12-02 22:10:16][DEBUG][zigate] : File already existing, make a backup before

Du coup j'ai mis un reboot automatique du demon si pas de communication pendant 30 minutes ...

Je suis sur une machine virtuelle debian sous proxmox .

On Mon, Dec 3, 2018 at 4:30 PM Sébastien RAMAGE notifications@github.com wrote:

Rien dans le log ? Tu fonctionnes sur quoi ? J'ai déjà eu ce genre de bizarrerie sur mon RPI quand la carte SD commence à mourrir

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-443750760, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoDk9NxtRsgaU8GKp91HaKuDZJ6Cjks5u1UONgaJpZM4YNNHs .

doudz commented 5 years ago

ah on est sur une machine virtuelle, on tient une piste, est-ce que ça sera pas la machine virtuelle qui ferme la redirection de port USB au bout d'un moment ?

ioull commented 5 years ago

Non je ne crois pas que ce soit un problème de deconnexion de port USB puisque je n'ai rien dans les logs de proxmox vers ces heures ci, c'était ma première idée ... l'envoi de commande continue de marcher donc le port USB est bein vue de la VM ...

Par contre si on peut mettre des logs autour de la reception USB et/ou de la deconnexion de port je suis prenneur.

Pour info, dans ma VM, j'ai également une clef zwave et un boitier rfxcom qui ne présente pas ces problèmes de taches HS.

Vincent.

Le lun. 3 déc. 2018 à 20:33, Sébastien RAMAGE notifications@github.com a écrit :

ah on est sur une machine virtuelle, on tient une piste, est-ce que ça sera pas la machine virtuelle qui ferme la redirection de port USB au bout d'un moment ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-443840345, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoABogaijtD-CKyvYgQMva6mWjH0gks5u1XyggaJpZM4YNNHs .

doudz commented 5 years ago

[2018-12-02 21:43:37][DEBUG] : create command 1.1027.16

Il se passe quoi dans le log avant cette ligne ?

ioull commented 5 years ago

On Tue, Dec 4, 2018 at 11:20 AM Sébastien RAMAGE notifications@github.com wrote:

[2018-12-02 21:43:37][DEBUG] : create command 1.1027.16

Il se passe quoi dans le log avant cette ligne ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-444048308, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoPDpPKe2sUaNCMhpItwuFzrhVhpqks5u1kxRgaJpZM4YNNHs .

doudz commented 5 years ago

Merci pour le log, effectivement rien d'anormal... et dans le log http.error, rien non plus ?

Par ailleurs, ça se produit toujours après 21H non ? yaurait pas autre chose qui se lance à ce moment là ?

ioull commented 5 years ago

Rien dans le http:.error nno plus :( Voici les dates de mes derniers reboot : [2018-12-03 20:25:03][SCENARIO] RESTART [2018-12-04 00:50:03][SCENARIO] RESTART [2018-12-04 21:50:05][SCENARIO] **** RESTART

Vincent.

On Wed, Dec 5, 2018 at 3:13 PM Sébastien RAMAGE notifications@github.com wrote:

Merci pour le log, effectivement rien d'anormal... et dans le log http.error, rien non plus ?

Par ailleurs, ça se produit toujours après 21H non ? yaurait pas autre chose qui se lance à ce moment là ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-444498663, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoM4jcey0UndTbB_fSyDJCu0VMnvkks5u19SCgaJpZM4YNNHs .

CaiRve commented 5 years ago

Salut,

J'ai exactement le meme pb !!! au moins une fois par jour `[2018-12-13 07:00:44][DEBUG][zigate] : Dispatch ZIGATE_ATTRIBUTE_UPDATED [2018-12-13 07:00:44][DEBUG][root] : External command ZIGATE_ATTRIBUTE_UPDATED : {'device': Device 00158d0001e52d33 (fbaa) lumi.sensor_motion.aq2, 'attribute': {'endpoint': 1, 'addr': 'fbaa', 'value': 24, 'name': 'luminosity', 'unit': 'lm', 'data': 24, 'cluster': 1024, 'attribute': 0}, 'zigate': <zigate.core.ZiGate object at 0x76317250>} [2018-12-13 07:00:44][DEBUG][zigate] : Dispatch ZIGATE_PACKET_RECEIVED Exception in thread ZiGate-Event Loop: Traceback (most recent call last): File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner self.run() File "/usr/lib/python3.5/threading.py", line 862, in run self._target(*self._args, **self._kwargs) File "/usr/local/lib/python3.5/dist-packages/zigate/core.py", line 156, in _event_loop self.decode_data(packet) File "/usr/local/lib/python3.5/dist-packages/zigate/core.py", line 377, in decode_data struct.unpack('!HHB%dsB' % (len(decoded) - 6), decoded) struct.error: bad char in struct format

[2018-12-13 07:00:44][DEBUG][root] : Send to jeedom : {'device': Device 00158d0001e52d33 (fbaa) lumi.sensor_motion.aq2, 'attribute': {'endpoint': 1, 'addr': 'fbaa', 'value': 24, 'name': 'luminosity', 'unit': 'lm', 'data': 24, 'cluster': 1024, 'attribute': 0}, 'action': 'ZIGATE_ATTRIBUTE_UPDATED'} [2018-12-13 07:00:44][DEBUG][requests.packages.urllib3.connectionpool] : Starting new HTTP connection (1): 127.0.0.1 [2018-12-13 07:00:44][DEBUG][requests.packages.urllib3.connectionpool] : http://127.0.0.1:8099 "POST /plugins/zigate/core/php/jeeZiGate.php?apikey=**** HTTP/1.1" 200 16 [2018-12-13 07:00:44][DEBUG][root] : Jeedom reply : {'success': True} [2018-12-13 07:02:19][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-13 07:02:19][DEBUG][zigate] : Saving persistent file [2018-12-13 07:02:19][DEBUG][zigate] : File already existing, make a backup before [2018-12-13 07:07:19][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-13 07:07:19][DEBUG][zigate] : Saving persistent file [2018-12-13 07:07:19][DEBUG][zigate] : File already existing, make a backup before [2018-12-13 07:12:19][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-13 07:12:19][DEBUG][zigate] : Saving persistent file [2018-12-13 07:12:19][DEBUG][zigate] : File already existing, make a backup before [2018-12-13 07:17:20][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-13 07:17:20][DEBUG][zigate] : Saving persistent file [2018-12-13 07:17:20][DEBUG][zigate] : File already existing, make a backup before [2018-12-13 07:22:20][DEBUG][zigate] : Auto saving /var/www/html/plugins/zigate/core/class/../../resources/zigated/.zigate.json [2018-12-13 07:22:20][DEBUG][zigate] : Saving persistent file `

je suis obligé de faire une restart du démon pour que cela refonctionne ....

doudz commented 5 years ago

Aaah là on a un traceback ,merci @CaiRve on avance

CaiRve commented 5 years ago

de rien je suis sur rpi3, la clé est sur un hub usb, et a priori pas de soucis de puissance

doudz commented 5 years ago

Donc a priori c'est un problème de décodage de paquet. c'est pas supposé arriver, ça veut dire que la zigate a envoyé un message incompréhensible @CaiRve est-ce que tu serais en mesure de modifier un fichier pour faire un essai ? (comme le problème arrive souvent chez toi) Si oui il faudrait modifier le fichier /usr/local/lib/python3.5/dist-packages/zigate/core.py avant la ligne 375 ajouter LOGGER.debug('Packet: {}'.format(hexlify(packet))) ça donnerait ça :

...
def decode_data(self, packet):
        '''
        Decode raw packet message
        '''
        LOGGER.debug('Packet: {}'.format(hexlify(packet)))
        decoded = self.zigate_decode(packet[1:-1])
...

ça va pas résoudre le problème mais c'est pour comprendre ce qu'il se passe

CaiRve commented 5 years ago

je fais ca et je redémarre le demon ?

ioull commented 5 years ago

Je ne pense pas que ce soit le même problème chez moi sinon j'aurais la même stack trace ... Cependant j'ai fait une modification hardware et ca semble ne plus se produire ... J'avais une rallonge USB entre la zigate et mon hub que j'ai supprimé ... Je vous redis ça ... mais à priori ca à l'air de ne plus planter !

Ce que je trouve bizarre, c'est que l'envoie marche malgré tout et c'est le retour qui est KO ... J'imagine également que si le lien pète, je devrais avoir un crash quelquepart dans la librairie ...

Bref est-ce que le problème que j'ai avec la rallonge ne peux pas arriver moins souvent sans rallonge et n'y a -t-il pas moyen de s'en prémunir ?

On Fri, Dec 14, 2018 at 12:17 PM Sébastien RAMAGE notifications@github.com wrote:

Donc a priori c'est un problème de décodage de paquet. c'est pas supposé arriver, ça veut dire que la zigate a envoyé un message incompréhensible @CaiRve https://github.com/CaiRve est-ce que tu serais en mesure de modifier un fichier pour faire un essai ? (comme le problème arrive souvent chez toi) Si oui il faudrait modifier le fichier /usr/local/lib/python3.5/dist-packages/zigate/core.py avant la ligne 375 ajouter LOGGER.debug('Packet: {}'.format(hexlify(packet))) ça donnerait ça :

...

def decode_data(self, packet):
    '''

    Decode raw packet message

    '''

    LOGGER.debug('Packet: {}'.format(hexlify(packet)))

    decoded = self.zigate_decode(packet[1:-1])
...

ça va pas résoudre le problème mais c'est pour comprendre ce qu'il se passe

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Jeedom-Zigate/jeedom-plugin-zigate/issues/81#issuecomment-447295503, or mute the thread https://github.com/notifications/unsubscribe-auth/AGHPoAzINF6nFFgGpaZtfeJLzCh7wj5gks5u44jUgaJpZM4YNNHs .

doudz commented 5 years ago

Oui et ensuite on attend que le problème revienne pour voir ce qu'il se passe dans le log

doudz commented 5 years ago

@ioull j'ai apporté une modification pour afficher un message d'erreur à la place d'un plantage (si c'est bien ça le problème)

CaiRve commented 5 years ago

j'ai eu un peu de mal a le faire redémarrer, au lieu d'espaces j'avais mis un tabulation, il avait pas aimé :-D Bon , en attente du prochain plantage.

doudz commented 5 years ago

Je pense que je commence à comprendre ce qu'il se passe, je crois que c'est vraiment un problème de communication entre la zigate et le système, à cause d'un HUB usb ou d'un mauvais câble, etc. Chaque message est fait comme ça : Début + Message + Fin Dans le cas de @CaiRve , il y a bien un Début et une Fin mais le message est incohérent d'où le plantage. Dans le cas de @ioull , je pense qu'il manque le Début d'un message, du coup le système reçoit probablement la suite et sans doute d'autres messages mais comme il manque le début il ne traite plus ce qui arrive. Je vais faire des essais dans ce sens et gérer ces cas particuliers.

doudz commented 5 years ago

Je pensais avoir résolu le problème, mais il vient de se produire chez moi... Je vais continuer à chercher

CaiRve commented 5 years ago

OK, au moins chez toi aussi cela peut arriver, ca me rassure ^^ en tout cas, de mon coté, le soucis ne s'est plus reproduit ...

jeedom-zigate / jeedom-plugin-zigate

Problème stabilité #81