Send en utilisant le cycle

Salon des Développeurs Aide Programmation
1

Bonjour,

J’aimerais implémenter un envoi de données du daemon (python) vers php en proposant un certain délais. L’idée étant d’accumuler un peu de données dans le daemon avant d’envoyer ça coté php pour économiser des ressources systèmes.

Actuellement les données sont dans un array data et j’utilise la seule fonction que je connais à savoir jeedom_com.send_change_immediate(data)

En regardant le code jeedom.py je vois qu’il y a des fonctions comme add_changes ou send_changes_async.

add_changes me semble utiliser la notion de cycle (que j’avais découvert dans openzwave) et qui devrait, je suppose, répondre au besoin en envoyant les données au bout du cycle que l’utilisateur définira.

Est-ce bien ça ? Quelle est la fonction à utiliser en fin de compte pour faire ça et surtout comment l’utiliser puisqu’elle n’attendent pas les mêmes arguments que send_change_immediate()

Merci pour le coup de main.

2

Bon alors j’ai mis un cycle de 4 et utilisé cette fonction dans le code python : jeedom_com.add_changes('blitzortung::data', data)

Je n’ai plus d’erreurs dans le daemon (faut que je change évidement le traitement coté PHP) mais ça ne fait pas le job parce que les events continues d’être envoyés comme ils arrivent donc parfois plusieurs fois par secondes.

3

T’es sur que tu as bien initialisé la variable cycle? tu la passes bien en paramètre lorsque tu crées ton jeeom_com?

4

Oui c’est OK de ce coté là :

logging.info('Start demond')
logging.info('Log level : '+str(_log_level))
logging.info('Socket port : '+str(_socket_port))
logging.info('Socket host : '+str(_socket_host))
logging.info('PID file : '+str(_pidfile))
logging.info('Apikey : '+str(_apikey))
logging.info('Cycle : '+str(_cycle))

signal.signal(signal.SIGINT, handler)
signal.signal(signal.SIGTERM, handler)	

try:
    jeedom_utils.write_pid(str(_pidfile))
    jeedom_com = jeedom_com(apikey = _apikey,url = _callback,cycle=_cycle)
    if not jeedom_com.test():
        logging.error('Network communication issues. Please fixe your Jeedom network configuration.')
        shutdown()
    jeedom_socket = jeedom_socket(port=_socket_port,address=_socket_host)
    listen()
except Exception as e:
	logging.error('Fatal error : '+str(e))
	logging.info(traceback.format_exc())
	shutdown()

Et dans les logs au démarrage j’ai bien :

19230|[2023-08-19 13:34:23]INFO : Start demond
19231|[2023-08-19 13:34:23]INFO : Log level : info
19232|[2023-08-19 13:34:23]INFO : Socket port : 56023
19233|[2023-08-19 13:34:23]INFO : Socket host : localhost
19234|[2023-08-19 13:34:23]INFO : PID file : /tmp/jeedom/blitzortung/deamon.pid
19235|[2023-08-19 13:34:23]INFO : Apikey : ---
19236|[2023-08-19 13:34:23]INFO : Cycle : 4.0
19237|[2023-08-19 13:34:23]INFO : Writing PID 24735 to /tmp/jeedom/blitzortung/deamon.pid

EDIT ; J’ai ajouté un bout de log dans jeedom.py

class jeedom_com():
	def __init__(self,apikey = '',url = '',cycle = 0.5,retry = 3):
		self.apikey = apikey
		self.url = url
		self.cycle = cycle
		self.retry = retry
		self.changes = {}
		if cycle > 0 :
			self.send_changes_async()
		logging.info('Init request module v%s' % (str(requests.__version__),))
		logging.info('Cycle dans jeedom_com ' + str(cycle))

Et j’ai bien un cycle à 4 :

19807|[2023-08-19 13:38:25]INFO : Start demond
19808|[2023-08-19 13:38:25]INFO : Log level : info
19809|[2023-08-19 13:38:25]INFO : Socket port : 56023
19810|[2023-08-19 13:38:25]INFO : Socket host : localhost
19811|[2023-08-19 13:38:25]INFO : PID file : /tmp/jeedom/blitzortung/deamon.pid
19812|[2023-08-19 13:38:25]INFO : Apikey : ----
19813|[2023-08-19 13:38:25]INFO : Cycle : 4.0
19814|[2023-08-19 13:38:25]INFO : Writing PID 30403 to /tmp/jeedom/blitzortung/deamon.pid
19815|[2023-08-19 13:38:25]INFO : Init request module v2.28.1
19816|[2023-08-19 13:38:25]INFO : Cycle dans jeedom_com 4.0
5

Je ne sais pas trop, t’as du rater un truc mais sans voir le code difficile de debug
t’as bien virer le send_change_immediate du coup?

sinon met du log dans add_changes

6

J’ai commenté le send_immediate avec un # oui
Je vais ajouter des logs dans add_changes mais je suis donc déjà rassuré sur le fait que c’est bien cette fonction qu’il faut utiliser.

J’update dès que j’ai du nouveau

7

@Mips,

Possible que je n’ai pas bien compris comment fonctionnait cette fonction aussi.

J’ai modifié avec ces logs pour analyse :

	def add_changes(self,key,value):
		logging.info('start add_changes function')
		if key.find('::') != -1:
			tmp_changes = {}
			changes = value
			logging.info('changes to add: '+str(changes))
			for k in reversed(key.split('::')):				
				if k not in tmp_changes:
					tmp_changes[k] = {}
				logging.info('tmp_changes : '+str(tmp_changes[k]))
				tmp_changes[k] = changes
				changes = tmp_changes
				tmp_changes = {}
			if self.cycle <= 0:
				logging.info('!!! cyle <= 0 : send to jeedom')
				self.send_change_immediate(changes)
			else:				
				logging.info('changes when cycle > 0 : '+str(changes))
				self.merge_dict(self.changes,changes)
				logging.info('merge_dict')
				logging.info('end add_changes function')
		else:
			logging.info('key not found')
			if self.cycle <= 0:
				self.send_change_immediate({key:value})
			else:
				self.changes[key] = value

J’appelle comme ça : jeedom_com.add_changes('blitzortung::impacts', data)

71406|[2023-08-19 15:14:43]INFO : start add_changes function
71407|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450875758334500, 'lat': 43.39207, 'lon': 19.262862, 'status': 0, 'region': 4, 'delay': 7.3, 'sig_num': 26}
71408|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71409|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71410|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450875758334500, 'lat': 43.39207, 'lon': 19.262862, 'status': 0, 'region': 4, 'delay': 7.3, 'sig_num': 26}}}
71411|[2023-08-19 15:14:43]INFO : merge_dict
71412|[2023-08-19 15:14:43]INFO : end add_changes function
71413|[2023-08-19 15:14:43]INFO : start add_changes function
71414|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879173591800, 'lat': 42.555941, 'lon': 18.942078, 'status': 1, 'region': 8, 'delay': 4, 'sig_num': 37}
71415|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71416|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71417|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879173591800, 'lat': 42.555941, 'lon': 18.942078, 'status': 1, 'region': 8, 'delay': 4, 'sig_num': 37}}}
71418|[2023-08-19 15:14:43]INFO : merge_dict
71419|[2023-08-19 15:14:43]INFO : end add_changes function
71420|[2023-08-19 15:14:43]INFO : start add_changes function
71421|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879173591800, 'lat': 42.555941, 'lon': 18.942078, 'status': 2, 'region': 9, 'delay': 4.1, 'sig_num': 37}
71422|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71423|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71424|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879173591800, 'lat': 42.555941, 'lon': 18.942078, 'status': 2, 'region': 9, 'delay': 4.1, 'sig_num': 37}}}
71425|[2023-08-19 15:14:43]INFO : merge_dict
71426|[2023-08-19 15:14:43]INFO : end add_changes function
71427|[2023-08-19 15:14:43]INFO : start add_changes function
71428|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879173602600, 'lat': 42.595529, 'lon': 18.925323, 'status': 1, 'region': 8, 'delay': 4.2, 'sig_num': 24}
71429|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71430|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71431|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879173602600, 'lat': 42.595529, 'lon': 18.925323, 'status': 1, 'region': 8, 'delay': 4.2, 'sig_num': 24}}}
71432|[2023-08-19 15:14:43]INFO : merge_dict
71433|[2023-08-19 15:14:43]INFO : end add_changes function
71434|[2023-08-19 15:14:43]INFO : start add_changes function
71435|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879173602600, 'lat': 42.595529, 'lon': 18.925323, 'status': 2, 'region': 9, 'delay': 4.3, 'sig_num': 24}
71436|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71437|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71438|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879173602600, 'lat': 42.595529, 'lon': 18.925323, 'status': 2, 'region': 9, 'delay': 4.3, 'sig_num': 24}}}
71439|[2023-08-19 15:14:43]INFO : merge_dict
71440|[2023-08-19 15:14:43]INFO : end add_changes function
71441|[2023-08-19 15:14:43]INFO : Send to jeedom : {'blitzortung': {'impacts': {'time': 1692450879173602600, 'lat': 42.595529, 'lon': 18.925323, 'status': 2, 'region': 9, 'delay': 4.3, 'sig_num': 24}}}
71442|[2023-08-19 15:14:43]INFO : start add_changes function
71443|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879582975500, 'lat': 32.193877, 'lon': -115.399909, 'status': 0, 'region': 3, 'delay': 4, 'sig_num': 27}
71444|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71445|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71446|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879582975500, 'lat': 32.193877, 'lon': -115.399909, 'status': 0, 'region': 3, 'delay': 4, 'sig_num': 27}}}
71447|[2023-08-19 15:14:43]INFO : merge_dict
71448|[2023-08-19 15:14:43]INFO : end add_changes function
71449|[2023-08-19 15:14:43]INFO : Send to jeedom : {'blitzortung': {'impacts': {'time': 1692450879582975500, 'lat': 32.193877, 'lon': -115.399909, 'status': 0, 'region': 3, 'delay': 4, 'sig_num': 27}}}
71450|[2023-08-19 15:14:43]INFO : start add_changes function
71451|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879661802000, 'lat': 34.163613, 'lon': -69.400261, 'status': 1, 'region': 0, 'delay': 4, 'sig_num': 40}
71452|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71453|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71454|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879661802000, 'lat': 34.163613, 'lon': -69.400261, 'status': 1, 'region': 0, 'delay': 4, 'sig_num': 40}}}
71455|[2023-08-19 15:14:43]INFO : merge_dict
71456|[2023-08-19 15:14:43]INFO : end add_changes function
71457|[2023-08-19 15:14:43]INFO : start add_changes function
71458|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879661798100, 'lat': 34.067375, 'lon': -69.310285, 'status': 1, 'region': 0, 'delay': 4.1, 'sig_num': 40}
71459|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71460|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71461|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879661798100, 'lat': 34.067375, 'lon': -69.310285, 'status': 1, 'region': 0, 'delay': 4.1, 'sig_num': 40}}}
71462|[2023-08-19 15:14:43]INFO : merge_dict
71463|[2023-08-19 15:14:43]INFO : end add_changes function
71464|[2023-08-19 15:14:43]INFO : Send to jeedom : {'blitzortung': {'impacts': {'time': 1692450879661798100, 'lat': 34.067375, 'lon': -69.310285, 'status': 1, 'region': 0, 'delay': 4.1, 'sig_num': 40}}}
71465|[2023-08-19 15:14:43]INFO : start add_changes function
71466|[2023-08-19 15:14:43]INFO : changes to add: {'time': 1692450879394134500, 'lat': 41.864613, 'lon': 19.958906, 'status': 1, 'region': 8, 'delay': 4.5, 'sig_num': 40}
71467|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71468|[2023-08-19 15:14:43]INFO : tmp_changes : {}
71469|[2023-08-19 15:14:43]INFO : changes when cycle > 0 : {'blitzortung': {'impacts': {'time': 1692450879394134500, 'lat': 41.864613, 'lon': 19.958906, 'status': 1, 'region': 8, 'delay': 4.5, 'sig_num': 40}}}
71470|[2023-08-19 15:14:43]INFO : merge_dict
71471|[2023-08-19 15:14:43]INFO : end add_changes function
71472|[2023-08-19 15:14:43]INFO : Send to jeedom : {'blitzortung': {'impacts': {'time': 1692450879394134500, 'lat': 41.864613, 'lon': 19.958906, 'status': 1, 'region': 8, 'delay': 4.5, 'sig_num': 40}}}

Donc 4 send to Jeedom dans la même seconde et de ce que je comprends de la fonction elle devrait concaténer les datas afin de les agglomérer non ? Et là, tmp_changes est toujours vide c’est bizarre non ?

Ce que je vois aussi c’est que je n’ai jamais de logs '!!! cyle <= 0 : send to jeedom' qui indique que le cycle n’est jamais inférieur à 0 alors que ça send quand même.

Bref je suis bien perdu pour le moment, une idée de ce que j’ai mal fait ?

8

tout a l’air correct dans le add_change, je ne vois rien

Dans la fonction send_changes_async change le log Send to jeedom: par Send to jeedom async: pour confirmer que tu passes bien par là; je suppose que oui et qu’il y a juste qlqch qui fait que le thread est relancé trop vite et que donc ca respecte pas tes 4s

9

J’ai passé le cycle à 40 pour voir un truc

3018|[2023-08-19 15:50:46]INFO : Send to jeedom async : {'blitzortung': {'impacts': {'time': 1692453042147954000, 'lat': 48.100821, 'lon': 24.717742, 'status': 1, 'region': 8, 'delay': 3.2, 'sig_num': 38}}}
3019|[2023-08-19 15:50:46]INFO : dt : 0:00:00.030852
3020|[2023-08-19 15:50:46]INFO : ms : 30.852
3021|[2023-08-19 15:50:46]INFO : timer_duration : 9.148
3022|[2023-08-19 15:50:55]INFO : Send to jeedom async : {'blitzortung': {'impacts': {'time': 1692453050964566000, 'lat': 43.04132, 'lon': 18.139309, 'status': 2, 'region': 9, 'delay': 4.3, 'sig_num': 25}}}
3023|[2023-08-19 15:50:55]INFO : dt : 0:00:00.022848
3024|[2023-08-19 15:50:55]INFO : ms : 22.848
3025|[2023-08-19 15:50:55]INFO : timer_duration : 17.152
3026|[2023-08-19 15:51:12]INFO : Send to jeedom async : {'blitzortung': {'impacts': {'time': 1692453068425634000, 'lat': 49.567324, 'lon': 18.940781, 'status': 1, 'region': 8, 'delay': 4.1, 'sig_num': 27}}}
3027|[2023-08-19 15:51:12]INFO : dt : 0:00:00.026296
3028|[2023-08-19 15:51:12]INFO : ms : 26.296
3029|[2023-08-19 15:51:12]INFO : timer_duration : 13.704

J’ai juste ajouté des infos pour savoir ce que donnait le timer_duration parce que sinon il est toujours négatif.

C’est « un peu mieux » en terme de cadence mais :
15:50:46 → 15:50:55 : 9s
15:50:55 → 15:51:12 : 17s

Ne donne ni un timing à 40s ni à 4s (je me demandais s’il fallait pas mettre 40 pour 4s)

Et surtout, il y eu des tas de passage par add_changes (que j’ai viré pour y voir plus clair) et le send to jeedom n’envoit que la dernière et pas du tout une concaténation de tout ce qui est arrivé entre les 2 envoies.

Mais encore une fois j’ai peut-être mal compris le but de cette fonction ?

Je cherche à accumuler de la donnée dans la fonction python et ne faire le send to jeedom qu’au bout de 4 ou 5 secondes mais avec un gros json de tout ce qui est arrivé entre temps. Est-ce que c’est bien à ça qu’est sensé servir add_changes ?

10

Oui mais un changement pour chaque clé je pense.
Donc si tu as plusieurs valeurs il va les écraser
L’idée c’est que c’est un « état » de la même chose donc pas besoin plus que 1 par cycle.

Reste le mystère que le délai est pas respecté mais faudrait voir si il n’y a pas un bug à ce niveau

11

Bon donc c’est pas du tout la notion de cycle qu’il faut que j’utilise.
Il faudrait que je trouve le moyen de le coder directement dans mon .py :thinking:

Et effectivement je capte par le comportement de cette fonction async :
Début du compteur

start_time = datetime.datetime.now()

Essai d’envoyer les chagements :

r = requests.post(self.url + '?apikey=' + self.apikey, json=changes, timeout=(0.5, 120), verify=False)

Récupération du temps de traitement en ms et différence avec la durée du cycle (qui devrait donc être logiquement en ms sinon ça n’a pas de sens)

dt = datetime.datetime.now() - start_time
ms = (dt.days * 24 * 60 * 60 + dt.seconds) * 1000 + dt.microseconds / 1000.0
timer_duration = self.cycle - ms

Dans mes exemple environ 30ms puis 22ms puis 26ms de traitement.

J’ai mis à un cycle de 40 donc le time_duration devient soit 0.1 soit la durée du cycle. Il faudrait donc que mon cycle soit défini à plus du double de la durée de traitement pour que la nouvelle programmation corresponde à mon cycle.

if timer_duration < 0.1 :
   timer_duration = 0.1
if timer_duration > self.cycle:
   timer_duration = self.cycle

Puis programmation, en seconde d’après la doc python, d’un temps avant de relancer la fonction async

resend_changes = threading.Timer(timer_duration, self.send_changes_async)
resend_changes.start()

J’ai l’impression qu’il y a un hic entre les secondes et les ms quelque part quand même.

12

J’ai donc redévelopper un bout de code en utilisant quand même le cycle mais sans les fonctions prévues avec le template de plugin puisque pour moi, ça ne fonctionne pas.

Je laisse ouvert au cas ou quelqu’un souhaite poursuivre l’analyse et corriger.

13

je me suis aussi posé la question et franchement ce n’est pas clair. De ce que je comprends il y a 2 problèmes si tu veux faire ça:

Le premier passage par send_changes_async prend bien la valeur de cycle avant de se relancer pour le 2ème passage mais par contre au 2ème passage lorsque ce calcul se fait:

timer_duration = self.cycle - ms

ça fait des secondes moins des millisecondes donc tu vas te retrouver quasiment toujours avec un timer_duration négatif. Le bon calcul est celui ci:

timer_duration = self.cycle - (ms/1000)

Et le 2ème problème tu l’as aussi évoqué c’est que ça ne renvoie que le dernier changement qui a été envoyé en non pas l’ensemble des changements qui ont eu lieu pendant ta période de cycle. Il faut certainement reprendre le code de la fonction mergi_dict:

	def merge_dict(self,d1, d2):
	    for k,v2 in d2.items():
	        v1 = d1.get(k) # returns None if v1 has no value for this key
	        if ( isinstance(v1, collections.Mapping) and
	             isinstance(v2, collections.Mapping) ):
	            self.merge_dict(v1, v2)
	        else:
	            d1[k] = v2

Si tu as une solution je suis preneur :wink:

++

14

et dans add_changes je ne comprends absolument pas ça:

			tmp_changes = {}
			changes = value
			for k in reversed(key.split('::')):
				if k not in tmp_changes:
					tmp_changes[k] = {}
				tmp_changes[k] = changes
				changes = tmp_changes
				tmp_changes = {}
15

Ces 2 fonctions ne font peut-être pas ce que tu as besoin mais ce n’est pas pour cela qu’elles ne sont pas correctes.
Mais tu peux t’en servir comme exemple pour implémenter ta logique :wink:

16

Hello,

Oui moi non plus j’ai rien compris donc j’ai développé un truc dans mon fichier .py sans toucher au reste. C’est surement pas au top mais ça fait ce que je voulais

J’initialise le timer, je fais le delta qui m’intéresse et quand il dépasse la durée du cycle j’envoie avec send_change_immediate

send_time = datetime.datetime.now()
while True:
....
....
                    if _cycle > 0:
                        time_delta = datetime.datetime.now() - send_time
                        diff_secondes = ((time_delta.days * 24 * 60 * 60 + time_delta.seconds) * 1000 + time_delta.microseconds / 1000.0) / 1000
                        if diff_secondes > _cycle and dataconcat != '':
                            logging.info("dataconcat : " + str(dataconcat))
                            jeedom_com.send_change_immediate(dataconcat)
                            dataconcat = ''
                            send_time = datetime.datetime.now()
                        else:
                            dataconcat = dataconcat + str(data) + ','
                    else:
                          jeedom_com.send_change_immediate(data)
17

tu fais un sleep qlq part dans ta boucle? sinon tu vas avoir le cpu à 100% sur ta boucle

18

Non, de ma compréhension (je découvre python et le websocket et j’ai repris 90% du code) c’est le websocket qui attend les données et qui lance les opérations :

while True:
    msg = await websocket.recv()
...

C’est pas bon comme ça ?

19

je sais pas ce que c’est ce websocket donc je peux pas te répondre, je suppose :person_shrugging:
tu fais tout dans la meme boucle?

20

je suis certain qu’il y a embrouille au niveau des millisecondes, fais le test et regarde ce que devient le cycle avant d’être relancé dans le timer, tu fais par exemple 10 secondes - 0.1 secondes mais en millisecondes => 10 - 100 tu vois le binz?