Demande optimisation du temps nécessaire envoi/reception de multi SMS

Franckybel · Juillet 19, 2022, 12:31

Bonjour,

J’utilise le plugin-sms depuis plusieurs années et je suis toujours surpris que ce plugin n’ai pas été amélioré afin d’optimiser les envois et réceptions, je m’explique.

L’envoi et la réception des SMS se fait unitairement avec une pause à chaque action d’envoi et réception, le temps est paramétrable dans le plugin, il est conseillé de ne pas descendre en dessous de 30 secondes pour ne pas surcharger la machine (c’est ma configuration).

Ceci est très pénalisant

En cas d’alarme par exemple (réception des alertes en décalé si plusieurs alertes envoyées à plusieurs personnes
En utilisant les interactions, le temps de réponse est très long au maximum une minute (2 fois 30 sec.).

On peut vérifier cela grace aux logs en mode Debug.

Premier scénario simple : Question à Jeedom sur un etat via SMS

Envoi d’un SMS à Jeedom avec la question 'Quelle est la température dans le couloir ?"
Même si la réception du SMS est effectuée par l’opérateur Jeedom va le réception après 30 sec.
interprétation par Jeedom via interaction (ultra rapide 1 seconde)
Envoi de la réponse 30 sec après
Pour ce scénario simple il faut 1 minute aujourd’hui pour recevoir une réponse de Jeedom via SMS
→ Amélioration possible : Quand un SMS est dans la file d’attente des envois, envoi du SMS, ce qui permettra d’avoir la réponse au bout de 31 ou 32 secondes en lieu et place de la minute

Second scénario : Envoi de plusieurs message à plusieurs personnes

Lors d’une alarme, Mon Jeedom envoie un SMS à ma femme et moi-même et cela pour chaque évènement
→ Jeedom ne lance qu’un SMS à la fois toutes les 30 secondes
Cela veut dire qu’au plus tard, le premier SMS est envoyé au bout de 30 secondes et le deuxième au bout d’une minute.
Si 2 états d’alarme, 4 SMS (2 par personne) sont envoyés le dernier SMS est envoyé après 2 minutes, même si vous avez désactivé l’alarme car dans la file d’attente.
→ Amélioration possible : Quand un SMS est envoyé et qu’un autre est dans la file, envoyé le prochain SMS puis vérification si SMS reçu (réception si un existe), puis envoi du prochain SMS.
En conclusion: effectuer les envois et réceptions en continu t’en que la file d’attente de réception ou d’envoi n’est pas vide, dès que les files sont vides, attente des 30 secondes.

Avez vous constaté le même comportement ?
Savez vous comment demander à l’équipe Jeedom de prendre en compte ce type d’amélioration ?

Mips · Juillet 19, 2022, 12:50

Bonjour,

Vous parlez de quelle config exactement? car aucune config ne se nomme « temps de pause » et je ne vois rien dans la doc qui parle de 30s non plus …

Si vous parlez du paramètre « cycle » il est dit de "ne pas descendre trop bas pour ne pas avoir d’instabilité; alors je vous accorde que « pas trop bas » c’est très vague mais personne ne parle de 30s non plus.
Et le problème ne sera pas sur jeedom je pense mais plus sur les échanges avec la clé.
Perso je suis sur un cycle à 10s et je n’ai pas de problème.

Donc faudrait p-e vérifier votre config et la documentation avant de demander des améliorations

Franckybel · Juillet 19, 2022, 2:49

Bonjour @Mips ,

Mon message n’est pas arrogant, je constate un fonctionnement qui peut être amélioré et je lis bien les documentations avec la vérification du comportement dans les LOGs.

Les 30 secondes (de cycle) étaient dans une réponse que j’avais eu sur ce même forum il y a quelques années (2 ou 3) par un développeurs Jeedom (il faudrait que je retrouve l’échange), il avait informé qu’il serait bien de revoir ce plugin qui datait au niveau développement (il avait même vérifié le comportement mais pas pris en compte car pas prioritaire).
Même si l’on descend le temps de cycle, le comportement reste le même, traitement unitairement de chaque action (une seule action par temps de cycle).

'Donc faudrait p-e vérifier votre config et la documentation avant de demander des améliorations".
Merci @Mips pour cette phrase anti communautaire.
J’ai participé dans d’autres Topics sur l’amélioration et le debug de fonctionnalités, je ne suis pas un expert mais un utilisateur actif qui veut bien prendre du temps voir perdre du temps à aider les autres (voir mes autres posts sur ce forum).
Ce type de phrase écrite est réellement contre productive, si vous voulez qu’une communauté s’éteigne, c’est le type de phrase qu’il faut écrire.
Vous êtres identifié comme modérateur.
Avez vous effectué tous les tests avec ce plugin pour constater la même comportement que je reporte ?

Mips · Juillet 19, 2022, 2:57

Désolé d’avoir répondu trop vite et du coup trop sèchement; repartons de meilleur pied
(mais je vais quand même répondre rapidement ici sous forme « bullet points » car je dois partir mais que je voulais vous répondre avant pour ne pas laisser la situation s’envenimer )

même si je ne l’avais pas précisé au-dessus, je ne contredit pas vos propos, je suis bien conscient du fait que cela se fait 1 par 1 etc
Je voulais juste:

être sur qu’on parle du même paramètre
et comprendre d’où venait le 30s
vous signaler que moi je suis déjà bien en-dessous (10s) sans soucis (et je ne suis pas descendu plus bas car je n’en avais pas besoin)

donc mon idée au départ était plutôt de suggérer que vous pourriez tester une valeur plus faible, 5s par exemple, et confirmer que tout vos sms sont toujours bien reçus et que vous n’avez pas de problème de « stabilité » général ni d’augmentation fulgurante de la charge, vous gagnerez déjà pas mal de temps et p-e que cela sera même un délai « acceptable » du coup?

Franckybel · Juillet 19, 2022, 3:06

ça marche, pas toujours bon de répondre rapidement
Etant maintenant sur un PI4B, je vais faire les tests en descendant le temps de cycle et contrôler que cela ne surcharge pas la bête.
Il faut juste faire attention car on essaie de réduire le temps de cycle et donc peut-être prendre un risque d’instabilité (à voir sur une salve d’envoi et réception) pour résoudre un ‹ problème › de base qui est le traitement unitaire d’un SMS à chaque temps de cycle.
Je tiens au courant d’ici demain

Franckybel · Juillet 19, 2022, 4:02

J’ai effectué les tests en descendant à 5 sec. le temps de cycle.
le CPU de mon PI4 (4GB) a pris environ 5% de charge supplémentaire mais insignifiant vis à vis de la puissance restante
Bien évidemment le comportement reste le même (traitement d’un SMS envoi/réception par cycle)
Sur une rafale de 10 sms (via un scénario), cela met presque une minute à arriver mais largement mieux qu’avant.
La réception de SMS avec interaction durant les envois n’a pas généré non plus de problème durant les tests.

Je laisse en fonctionnement sur les prochains jours avec un suivi des Logs (que j’ai mis en debug au cas où). Si pb je fais un retour sur ce poste.

Merci pour l’aide sur la diminution du temps de cycle.
je ne sais pas comment informer l’équipe Jeedom pour prendre en compte le fait d’envoyer des SMS sans attendre le temps de cycle (si 10 SMS à envoyer à 2 personnes, ne pas attendre plus de 2 minutes avant d’envoyer la totalité mais le faire en temps réel )

Mips · Juillet 19, 2022, 8:47

J’ai vérifié le code et traiter « tous les sms » à chaque cycle n’est pas une bonne idée sans laisser un tout petit peu de temps entre chaque et donc au final cela revient à diminuer le cycle très fortement, à 1s.
Donc si 5s n’est pas assez rapide vous devriez tester 1s.

En passant, j’en ai profité pour migrer le plugin (et son démon) sur python3 pour qu’il soit prêt pour debian 11, si ca vous tente de tester et me faire un retour, cela serait utile

edit: et j’oubliais, un post sur community est le bon moyen de remonter une idée de changement à l’équipe

Franckybel · Juillet 20, 2022, 6:54

Super merci @Mips,
Je vais tester également ce soir en descendant à 1s.

Autre petit point au niveau des logs lorsque j’ai effectué les tests hier
lorsque les log sont au niveau ‹ Info ›, nous avons bien les informations sur l’initialisation du service, sur la réception des SMS (voir capture écran ci-dessous) mais il n’est pas affiché l’information sur l’envoi des sms.
J’ai du me mettre en mode ‹ debug › pour voir la réception et l’envoi des sms (pas facile à lire mais logique puisque du debug )

Peut-être une modif à intégrer également pour le log en mode info …

Franckybel · Juillet 20, 2022, 8:20

@Mips test KO est Jeedom plugin plus fonctionnel.

Je viens de faire les tests en passant à 1s et mon service SMS ne fonctionne plus.
Même si je repasse à 30 sec. par exemple le temps n’est visiblement pas pris en compte et reste à 1 sec.
Le service SMS n’est plus fonctionnel sur mon Jeedom ni envoi ni réception de SMS

Voici le fichier LOG joint ou l’on voit bien le temps cycle passé à 30 sec mais les appels au modem restent à 1 sec.

[2022-07-20 09:53:14][DEBUG] : Lancement de : /var/www/html/core/class/../../core/php/jeePlugin.php  plugin_id=sms function=remove callInstallFunction=1
[2022-07-20 09:53:21][INFO] : Début d'activation du plugin
[2022-07-20 09:53:22][INFO] : Info sur le démon : {"launchable_message":"","launchable":"nok","state":"nok","log":"nok","auto":0}
[2022-07-20 09:53:22][DEBUG] : Lancement de : /var/www/html/core/class/../../core/php/jeePlugin.php  plugin_id=sms function=install callInstallFunction=1
[2022-07-20 09:53:48][ERROR] : Erreur sur la fonction deamon_start du plugin : Vous devez attendre au moins 45 secondes entre deux lancements du démon. Dernier lancement : 2022-07-20 09:53:26
[2022-07-20 09:54:03][ERROR] : Erreur sur la fonction deamon_start du plugin : Vous devez attendre au moins 45 secondes entre deux lancements du démon. Dernier lancement : 2022-07-20 09:53:26
[2022-07-20 09:54:17][INFO] : Lancement démon sms : /usr/bin/python /var/www/html/plugins/sms/resources/smsd/smsd.py --device /dev/ttyUSB2 --loglevel debug --socketport 55002 --serialrate 115200 --pin None --textmode no --smsc None --cycle 30 --callback http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php --apikey aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW --pid /tmp/jeedom/sms/deamon.pid
[2022-07-20 09:54:18][INFO] : Start smsd
[2022-07-20 09:54:18][INFO] : Log level : debug
[2022-07-20 09:54:18][INFO] : Socket port : 55002
[2022-07-20 09:54:18][INFO] : Socket host : 127.0.0.1
[2022-07-20 09:54:18][INFO] : PID file : /tmp/jeedom/sms/deamon.pid
[2022-07-20 09:54:18][INFO] : Device : /dev/ttyUSB2
[2022-07-20 09:54:18][INFO] : Apikey : aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW
[2022-07-20 09:54:18][INFO] : Callback : http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php
[2022-07-20 09:54:18][INFO] : Cycle : 30.0
[2022-07-20 09:54:18][INFO] : Serial rate : 115200
[2022-07-20 09:54:18][INFO] : Pin : None
[2022-07-20 09:54:18][INFO] : Text mode : no
[2022-07-20 09:54:18][INFO] : SMSC : None
[2022-07-20 09:54:18][DEBUG] : Writing PID 13351 to /tmp/jeedom/sms/deamon.pid
[2022-07-20 09:54:18][DEBUG] : Init request module v2.21.0
[2022-07-20 09:54:18][DEBUG] : Starting new HTTP connection (1): 127.0.0.1:80
[2022-07-20 09:54:18][DEBUG] : http://127.0.0.1:80 "GET /plugins/sms/core/php/jeeSMS.php?apikey=aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW HTTP/1.1" 200 0
[2022-07-20 09:54:18][DEBUG] : Socket interface started
[2022-07-20 09:54:18][DEBUG] : LoopNetServer Thread started
[2022-07-20 09:54:18][DEBUG] : Start listening...
[2022-07-20 09:54:18][DEBUG] : Listening on: [127.0.0.1:55002]
[2022-07-20 09:54:18][DEBUG] : Connecting to GSM Modem...
[2022-07-20 09:54:18][DEBUG] : Text mode false
[2022-07-20 09:54:18][INFO] : Connecting to modem on port /dev/ttyUSB2 at 115200bps
[2022-07-20 09:54:18][DEBUG] : write: ATZ
[2022-07-20 09:54:18][DEBUG] : response: ['OK']
[2022-07-20 09:54:18][DEBUG] : write: ATE0
[2022-07-20 09:54:18][DEBUG] : response: ['OK']
[2022-07-20 09:54:18][DEBUG] : write: AT+CFUN?
[2022-07-20 09:54:18][DEBUG] : response: ['+CFUN: 1', 'OK']
[2022-07-20 09:54:18][DEBUG] : write: AT+CMEE=1
[2022-07-20 09:54:18][DEBUG] : response: ['OK']
[2022-07-20 09:54:18][DEBUG] : write: AT+CPIN?
[2022-07-20 09:54:18][DEBUG] : response: ['+CPIN: READY', 'OK']
[2022-07-20 09:54:18][DEBUG] : write: AT+CLAC
[2022-07-20 09:54:19][DEBUG] : response: ['H', 'A', 'D', 'O', 'S0', 'S3', 'S4', 'S5', 'S6', 'S7', 'E', 'V', 'I', 'T', 'P', 'X', 'Z', 'Q', '&C', '&D', '&S', '&F', '+CPBS', '+CPBR', '+CPBW', '+CNUM', '+CPBF', '+CSIM', '+CCHO', '+CCHC', '+CGLA', '+CPIN', '+CRSM', '+CSCS', '+CMEE', '+CSDH', '+CNMI', '+CMMS', '+CMGF', '+CGSMS', '+CSCA', '+CSMS', '+CSMP', '+CPMS', '+CMGD', '+CSCB', '+CLVL', '+CHUP', '+CLCC', '+CPAS', '+CBST', '+CMOD', '+CSTA', '+VTS', '+CRC', '+CLIP', '+CLIR', '+COLP', '+CCUG', '+CSSN', '+CHLD', '+CUUS1', '+CCWA', '+CCFC', '+CUSD', '+GMR', '+GMI', '+CPWD', '+CLCK', '+CGATT', '+COPS', '+CGCLASS', '+CFUN', '+CGMI', '+CGMM', '+GMM', '+CGMR', '+CGSN', '+GSN', '+CIMI', '+CSQ', '+CBC', '+CLAC', '+GCAP', '+CPLS', '+CPOL', '+CREG', '+CGREG', '+CEREG', '+CGDCONT', '+CGDSCONT', '+CGTFT', '+CGACT', '+CGCMOD', '+CGPADDR', '+CGEQNEG', '+CGANS', '^CGANS', '^APENDPPP', '+CGDATA', '+CGEQREQ', '+CGEQMIN', '+CGAUTO', '+CTZR', '+CGCONTRDP', '+CGSCONTRDP', '+CGTFTRDP', '+CGEQOS', '+CGEQOSRDP', '+CPOS', '+CPOSR', '+CMUT', '+COPN', '+IPR', '+ICF', '+IFC', '+CCLK', '^AT2OM', '^CPBR', '^CPBW', '^SCPBW', '^SCPBR', '^STSF', '^CSTR', '^CSIN', '^CSEN', '^CSMN', '^CSTC', '^STGI', '^STGR', '^IMSICHG', '^ICCID', '^CPIN', '^PNN', '^CPNN', '^OPL', '^CARDLOCK', '^CARDATR', '^CMSR', '^CMGI', '^CMMT', '^APTHROUGHPUT', '^APDIALMODE', '^APCONNST', '^APPDMVER', '^OPWORD', '^CPWORD', '^SPWORD', '^SHELL', '^RSRPCFG', '^RSCPCFG', '^ECIOCFG', '^PDPROFMOD', '^SCID', '+CSQLVL', '^CSQLVLEXT', '^DISSD', '^SDREBOOT', '^DOCK', '^APCRADWIFIBS', '^APNDISCON', '^APCRADETHSTA', '^APFMCDHCPSTA', '^APDIALM', '^APWIFIBS', '^APWIFISEC', '^APDHCP', '^APCURPROF', '^APPROFRD', '^APBATLVL', '^OPENPORT', '^APPDIALMODE', '^LCSTARTTIME', '^DLOADVER', '^DLOADINFO', '^AUTHORITYVER', '^AUTHORITYID', '^NVBACKUP', '^NVRESTORE', '^GODLOAD', '^RESET', '^NVRSTSTTS', '^FLASHINFO', '^WIFIGLOBALMAC', '^SDLOAD', '^AUTHVER', '^CDUR', '^PFVER', '^IPV6CAP', '^DHCPV6', '^APRAINFO', '^APLANADDR', '^APRPTSRVURL', '^APXMLINFOTYPE', '^APXMLRPTFLAG', '^RSTRIGGER', '^VMSET', '^DTMF', '^ALS', '^APPWRONREG', '^ANQUERY', '^APHPLMN', '^VERTIME', '^FREQLOCK', '^CSNR', '^HSPA', '^COMM', '^CRPN', '^GETPORTMODE', '^PORTSEL', '^DIALMODE', '^CARDMODE', '^SPN', '^CCC', '^MEANRPT', '^CELLINFO', '^CGAS', '^CWAS', '^CMLCK', '^GCFIND', '^CGCATT', '^CPDW', '^HWVER', '^HVER', '^FHVER', '^SRVST', '^CERSSI', '^MODE', '^SIMST', '^HS', '^CFPLMN', '^CQST', '^CAATT', '^SYSINFO', '^SYSINFOEX', '+CEMODE', '^LTECS', '^SYSCFG', '^SYSCFGEX', '^NETSCAN', '^PCSCINFO', '^CELLSRCH', '^CPAM', '^NDISSTATQRY', '^AUTHDATA', '^DHCP', '^DSFLOWCLR', '^DSFLOWQRY', '^NDISDUP', '^NDISCONN', '^NDISADD', '^CGDNS', '^TRIG', '^DSFLOWRPT', '^TIME', '^PDPSTUB', '^U2DIAG', '^GLASTERR', '^DNSP', '^DNSS', '^SETPORT', '^USBSPEED', '^FASTDORM', '^ACPUMEMINFO', '^CCPUMEMINFO', '^CIPHERQRY', '^LOCINFO', '^QRYNVRESUME', '^NVBACKUPSTAT', '^NANDBBC', '^NANDVER', '^CHIPTEMP', '^CPIN2', '^DNSQUERY', '^CSASM', '^APRPTPORTSEL', '^CHDATA', '+USBSWITCH', '^GPIO', '^RSFR', '^RSFW', '^ANTSTATE', '^SARREDUCTION', '^APSIMST', '^NVM', '^XCPOSR', '^CGPSCLOCK', '^CGPSINFO', '^LOGCFG', '^LOGSAVE', '^CPSERR', '^APSEC', '^CISA', '^APDS', '^CLPR', '^CCSERR', '^WLTHRESHOLDCFG', '^ACINFO', '^CLTEROAMALLOW', '^SWVER', '^DLCK', '^CBG', '^MMPLMNINFO', '^PLMN', '^XLEMA', '^BODYSARON', '^BODYSARWCDMA', '^BODYSARGSM', '^IMEIVERIFY', '^LOGPORT', '^NCELLMONITOR', '^USERSRVSTATE', '^SIMSLOT', '^SIMINSERT', '^MODEMLOOP', '^RELEASERRC', '^REFCLKFREQ', '^PULLOMLOG', '^REJINFO', '^PLMNSELEINFO', '^DIESN', '^CHIPSN', '^HANDLEDECT', '^HVSDH', '^HVSST', '^HVSCONT', '^HVPDH', '^NWSCAN', '^NWTIME', '^LTERSRP', '^HCSQ', '^EONS', '^HGMR', '^HFREQINFO', '^EOPLMN', '+ECID', '^UARTSWITCH', '^SMSREGST', '^SETMODE', '^LTECAT', '^GTIMER', '^RSIM', '^PHYNUM', '^CSVER', '^QOS', '^SDOMAIN', '^DPACAT', '^HSSPT', '^PLATFORM', '^BSN', '^SFM', '^TMODE', '^FCHAN', '^FTXON', '^FDAC', '^FRXON', '^FPA', '^FLNA', '^FRSSI', '^MDATE', '^FACINFO', '^SD', '^GPIOPL', '^GETEXBANDINFO', '^GETEXBANDTESTINFO', '^INFORRS', '^INFORBU', '^DATALOCK', '^VERSION', '^SIMLOCK', '^MAXLCKTMS', '^CALLSRV', '^CSDFLT', '^SECUBOOTFEATURE', '^SECUBOOT', '^TMMI', '^TCHRENABLE', '^TCHRINFO', '^TSCREEN', '^TBATVOLT', '^WUPWD', '^PRODTYPE', '^SFEATURE', '^PRODNAME', '^FWAVE', '^EQVER', '^WIENABLE', '^WIMODE', '^WIBAND', '^WIFREQ', '^WIDATARATE', '^WIPOW', '^WITX', '^WIRX', '^WIRPCKG', '^SSID', '^WIKEY', '^WILOG', '^WIINFO', '^WIPARANGE', '^NVRD', '^NVWR', '^CURC', '^SN', '^TBAT', '^PSTANDBY', '^WIWEP', '^CMDLEN', '^TSELRF', '^HUK', '^FACAUTHPUBKEY', '^IDENTIFYSTART', '^IDENTIFYEND', '^SIMLOCKDATAWRITE', '^PHONESIMLOCKINFO', '^SIMLOCKDATAREAD', '^PHONEPHYNUM', '^PORTCTRLTMP', '^PORTATTRIBSET', '^SIMLOCKUNLOCK', '^EXTCHARGE', '^WUSITE', '^WIPIN', '^WUUSER', '^PORTLOCK', '^TBATDATA', '^WIPLATFORM', '^ANTENNA', '^FPLLSTATUS', '^MDLOGENABLE', '^BANDSW', '^FCHANS', '^FSEGMENT', '^FPOWS', '^FPAS', '^FLNAS', '^FTXWAVE', '^FSTART', '^FRSSIS', '^FCMTMS', '^FBLK', '^FIPSTART', '^FMAXPOWER', '^FPAPOWER', '^FPDMS', '^FCALIIP2S', '^FCALIDCOCS', '^FCALIIP2SMRF', '^FCALIDCOCSMRF', '^FGAINSTATES', '^FDBBATTS', '^FBBATTS', '^FCALITXIQS', '^FVCTCXO', '^FCALPDDCS', '^FPDPOWS', '^FQPDDCRES', '^NVRDLEN', '^NVRDEX', '^NVWREX', '^SSYNC', '^STXBW', '^STXCHAN', '^SSUBFRAME', '^SPARA', '^SSEGNUM', '^STXMODUS', '^STXRBNUMS', '^STXRBPOSS', '^STXPOWS', '^STXCHANTYPES', '^SSEGLEN', '^SRXSET', '^SRXSUBFRA', '^SRXMEAS', '^SSTART', '^SSTOP', '^STCFGDPCH', '^FPOW', '^STRXMEAS', '^SCELLINFO', '^SCALIB', '^CMTM', '^LTCOMMCMD', '^LWCLASH', '^LCACELL', 'OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CGMI
[2022-07-20 09:54:19][DEBUG] : response: ['huawei', 'OK']
[2022-07-20 09:54:19][INFO] : Loading Huawei call state update table
[2022-07-20 09:54:19][DEBUG] : write: AT+COPS=3,0
[2022-07-20 09:54:19][DEBUG] : response: ['OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CMGF=0
[2022-07-20 09:54:19][DEBUG] : response: ['OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CSCA?
[2022-07-20 09:54:19][DEBUG] : response: ['+CSCA: "+33609001390",145', 'OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CSMP=49,167,0,0
[2022-07-20 09:54:19][DEBUG] : response: ['OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CSCA?
[2022-07-20 09:54:19][DEBUG] : response: ['+CSCA: "+33609001390",145', 'OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CPMS=?
[2022-07-20 09:54:19][DEBUG] : response: ['+CPMS: ("SM","ME"),("SM","ME"),("SM","ME")', 'OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CPMS="ME","ME","ME"
[2022-07-20 09:54:19][DEBUG] : response: ['+CPMS: 0,20,0,20,0,20', 'OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CNMI=2,1,0,2
[2022-07-20 09:54:19][DEBUG] : response: ['OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CLIP=1
[2022-07-20 09:54:19][DEBUG] : response: ['OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CRC=1
[2022-07-20 09:54:19][DEBUG] : response: ['OK']
[2022-07-20 09:54:19][DEBUG] : write: AT+CVHU=0
[2022-07-20 09:54:19][DEBUG] : response: ['COMMAND NOT SUPPORT']
[2022-07-20 09:54:19][DEBUG] : Waiting for network...
[2022-07-20 09:54:19][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:19][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:20][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:20][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:21][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:21][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:22][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:22][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:23][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:23][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:24][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:24][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:25][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:25][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:26][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:26][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:27][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:27][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:28][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:28][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:29][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:29][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:30][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:30][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57696]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 1"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57696]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57698]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 2"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57698]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57700]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 3"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57700]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57702]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 4"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57702]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57704]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 5"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57704]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57706]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 6"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57706]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57708]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 7"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57708]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57710]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 8"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57710]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57712]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 9"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57712]
[2022-07-20 09:54:31][DEBUG] : Client connected to [127.0.0.1:57714]
[2022-07-20 09:54:31][DEBUG] : Message read from socket: {"apikey":"aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW","number":"06xxxxxxxx","message":"Envoi du SMS 09:54 - 10"}
[2022-07-20 09:54:31][DEBUG] : Client disconnected from [127.0.0.1:57714]
[2022-07-20 09:54:31][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:31][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:32][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:32][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:33][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:33][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:34][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:34][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:35][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:35][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:36][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:36][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:37][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:37][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:38][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:38][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:39][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:39][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:40][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:40][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:41][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:41][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:42][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:42][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:43][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:43][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:44][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:44][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:45][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:45][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:46][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:46][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:47][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:47][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:48][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:48][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:49][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:49][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:50][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:50][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:51][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:51][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:52][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:52][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:53][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:53][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:54][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:54][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:55][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:55][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:56][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:56][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:57][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:57][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:58][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:58][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:54:59][DEBUG] : write: AT+CREG?
[2022-07-20 09:54:59][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:00][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:00][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:01][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:01][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:02][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:02][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:03][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:03][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:04][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:04][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:05][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:05][DEBUG] : response: ['+CREG: 0,2', 'OK']
[2022-07-20 09:55:06][DEBUG] : write: AT+CREG?
[2022-07-20 09:55:06][DEBUG] : response: ['+CREG: 0,2', 'OK']

Que dois je faire pour revenir sur une situation stable ?

J’explique :

J’ai passé le temps de cycle à 1s
mis les log en debug
redémarré le demon
lancé ma rafale de 10 sms
le Plugin Prend bien compte mes 10 SMS dans la file (visible dans le LOG)
Aucun envoi de SMS

Voulu faire un rollback et revenir à 30 sec

J’ai passé le temps de cycle à 30 sec.
redémarré le demon
lancé ma rafale de 10 sms
le Plugin Prend bien compte mes 10 SMS dans la file
Aucun envoi de SMS et Aucune réception de sms également
J’ai constaté à ce moment que le cycle reste à 1sec.
J’ai désactivé le plugin et réactivé aucun changement le temps cycle semble reste à 1 Sec. même si configuré à 30 sec., aucun envoi de SMS ou réception de SMS

Mips · Juillet 20, 2022, 8:37

Je ne sais pas, on dirait qu’un thread est resté actif avec l’ancienne config, essayez de redémarrer ou de débrancher la clé, tout stopper et rebrancher
Donc 1s c’est trop bas

Aussi faut se demander si l’opérateur va pas bloquer qlqch si plein de sms sont envoyés si rapidement, ce n’est pas un comportement « normal »

Franckybel · Juillet 20, 2022, 8:46

Merci pour ton retour rapide.
J’ai débranché la clé et tout est revenu à la normal.
Je suis resté à 5 sec.

Comme tu informes, 1sec est trop bas et la suggestion à 5 sec. semble raisonnable.

Que penses tu concernant le LOG au niveau ‹ info › pour inscrire aussi les sms envoyés ?

Mips · Juillet 20, 2022, 12:46

Ca sera dans la beta demain

Franckybel · Juillet 21, 2022, 9:22

@Mips, Je viens d’installer la béta.
Le deamon ne veut pas démarrer, lorsque je réinstall la version stable, aucun problème
voici l’extrait du log, si besoin plus d’info, n’hésite pas

[2022-07-21 11:10:47][INFO] : Info sur le démon : {"log":"sms","state":"nok","launchable":"ok","launchable_message":"Gestion automatique d\u00e9sactiv\u00e9e","auto":"0","last_launch":"2022-07-21 11:09:52"}
[2022-07-21 11:11:06][INFO] : Lancement démon sms : /usr/bin/python3 /var/www/html/plugins/sms/resources/smsd/smsd.py --device /dev/ttyUSB2 --loglevel info --socketport 55002 --serialrate 115200 --pin None --textmode no --smsc None --cycle 5 --callback http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php --apikey aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW --pid /tmp/jeedom/sms/deamon.pid
Error: importing module from jeedom folder
[2022-07-21 11:11:38][ERROR] : Impossible de lancer le démon sms, vérifiez le port
[2022-07-21 11:11:56][INFO] : Lancement démon sms : /usr/bin/python3 /var/www/html/plugins/sms/resources/smsd/smsd.py --device /dev/ttyUSB2 --loglevel debug --socketport 55002 --serialrate 115200 --pin None --textmode no --smsc None --cycle 5 --callback http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php --apikey aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW --pid /tmp/jeedom/sms/deamon.pid
Error: importing module from jeedom folder
[2022-07-21 11:12:28][ERROR] : Impossible de lancer le démon sms, vérifiez le port
[2022-07-21 11:13:37][INFO] : Lancement démon sms : /usr/bin/python3 /var/www/html/plugins/sms/resources/smsd/smsd.py --device /dev/ttyUSB2 --loglevel debug --socketport 55002 --serialrate 115200 --pin None --textmode no --smsc None --cycle 5 --callback http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php --apikey aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW --pid /tmp/jeedom/sms/deamon.pid
Error: importing module from jeedom folder
[2022-07-21 11:14:09][ERROR] : Impossible de lancer le démon sms, vérifiez le port
[2022-07-21 11:14:57][DEBUG] : Lancement de : /var/www/html/core/class/../../core/php/jeePlugin.php  plugin_id=sms function=pre_update callInstallFunction=1
[2022-07-21 11:14:58][INFO] : Début d'activation du plugin
[2022-07-21 11:14:59][INFO] : Info sur le démon : {"log":"sms","state":"nok","launchable":"ok","launchable_message":"Gestion automatique d\u00e9sactiv\u00e9e","auto":"0","last_launch":"2022-07-21 11:13:36"}
[2022-07-21 11:14:59][DEBUG] : Lancement de : /var/www/html/core/class/../../core/php/jeePlugin.php  plugin_id=sms function=update callInstallFunction=1
[2022-07-21 11:15:05][INFO] : Lancement démon sms : /usr/bin/python /var/www/html/plugins/sms/resources/smsd/smsd.py --device /dev/ttyUSB2 --loglevel debug --socketport 55002 --serialrate 115200 --pin None --textmode no --smsc None --cycle 5 --callback http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php --apikey aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW --pid /tmp/jeedom/sms/deamon.pid
[2022-07-21 11:15:06][INFO] : Start smsd
[2022-07-21 11:15:06][INFO] : Log level : debug
[2022-07-21 11:15:06][INFO] : Socket port : 55002
[2022-07-21 11:15:06][INFO] : Socket host : 127.0.0.1
[2022-07-21 11:15:06][INFO] : PID file : /tmp/jeedom/sms/deamon.pid
[2022-07-21 11:15:06][INFO] : Device : /dev/ttyUSB2
[2022-07-21 11:15:06][INFO] : Apikey : aaN0VG4wjfQfuxwywOMwJtQT7qxIUahW
[2022-07-21 11:15:06][INFO] : Callback : http://127.0.0.1:80/plugins/sms/core/php/jeeSMS.php
[2022-07-21 11:15:06][INFO] : Cycle : 5.0
[2022-07-21 11:15:06][INFO] : Serial rate : 115200
[2022-07-21 11:15:06][INFO] : Pin : None
[2022-07-21 11:15:06][INFO] : Text mode : no
[2022-07-21 11:15:06][INFO] : SMSC : None
[2022-07-21 11:15:06][DEBUG] : Writing PID 28589 to /tmp/jeedom/sms/deamon.pid

Mips · Juillet 21, 2022, 9:47

OK j’ai du oublier une dépendance
Je vais vérifier ça.

Merci pour le retour

Mips · Juillet 21, 2022, 11:06

Voila, cela sera fixé dans la beta de demain.

J’ai aussi testé sur bullseye (debian 11) et je vois qu’il y a des petits warnings de syntaxe dans le log mais cela ne devrait pas être bloquant, je fixerai cela aussi à l’occasion.

Franckybel · Juillet 22, 2022, 8:42

J’ai effectué les tests ce matin, tout fonctionne parfaitement.
Le seul point, l’installation des dépendances étaient NOK après installation du plugin.
J’ai juste relance l’installation des dépendances et tout à fonctionner sans problème

Mips · Juillet 22, 2022, 8:58

Pour mon info, êtes-vous déjà en 4.2 ou une version inférieur?
la procédure d’install des dépendances n’est pas la même et je n’ai plus de version <4.2 pour tester

Franckybel · Juillet 22, 2022, 12:10

Je suis en version 4.2.12, je passerai en 4.2.20 ce week-end

tchirou · Septembre 19, 2023, 8:59

Hello.
Je confirme que dans un scénario où plusieurs sms doivent être envoyés, il y a un temps important de latence entre le premier et le dernier (parfois jusqu’à 5 minutes), même avec un cycle de 5 secondes
Je ne sais pas si c’est vraiment + optimisable mais je m’abonne à cette discussion au cas où

Mips · Septembre 19, 2023, 6:25

Il n’y aura rien de plus dans le plugin, tout est configurable déjà.
Mais lisez les posts précédents, à 1s c’est un risque de crash, tout dépend de la machine.

Ceci dit relisez aussi ma réponse déjà faite à ce propos: pas convaincu que ça soit une bonne approche d’envoyer 60 sms en un coup (puisque apparemment ca prend 5min).
ne me faite pas croire que vous avez 60 notifs à envoyer en un seul scénario pour votre propre usage…

Ce plugin n’est pas un outil d’envoi de sms en masse.

Pour s’abonner un à sujet, pas la peine de le déterrer il suffit d’activer le suivi (la petite cloche)