Instabilité téléphone Gammu à suivre...

[FredMa01]

Ce problème est abordé dans cette issue : #155
Raspisms fonctionne parfaitement jusqu'à un moment où un redémarrage du raspberry ne laisse plus les SMS entrer, sans que je ne parvienne à comprendre cette instabilité.
Le problème provient certainement de Gammu...

Raspisms a bien démarré : service raspisms status

● raspisms.service - RaspiSMS Daemons
   Loaded: loaded (/usr/share/raspisms/confs/systemd/raspisms.service; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2021-03-01 15:41:46 CET; 8min ago
     Docs: https://raspisms.raspberry-pi.fr
  Process: 636 ExecStart=/usr/share/raspisms/bin/start.sh (code=exited, status=0/SUCCESS)
 Main PID: 1071 (php)
    Tasks: 7 (limit: 2181)
   CGroup: /system.slice/raspisms.service
           ├─1071 RaspiSMS Daemon Launcher
           ├─1076 RaspiSMS Daemon Sender
           ├─1078 RaspiSMS Daemon Webhook
           ├─1085 RaspiSMS Daemon Mailer
           ├─1349 RaspiSMS Daemon Phone 11
           ├─1502 sh -c /usr/share/raspisms/bin/gammu_get_unread_sms.py '/etc/gammurc' 2>&1
           └─1503 python3 /usr/share/raspisms/bin/gammu_get_unread_sms.py /etc/gammurc

Fichier de config : /etc/gammurc

[gammu]
device = /dev/ttyUSB-3G
model =
connection = at19200
synchronizetime = yes
logfile = /var/log/gammu.log
logformat = textalldate
gammu_coding = utf8
use_locking =
gammuloc =
atgen_setCNMI=1,2,0,0,0
DeliveryReport = sms

Log Gammu :

Mon 2021/03/01 15:13:12: SENDING frame type 0x00/length 0x05/5
Mon 2021/03/01 15:13:12: 41A|54T|45E|311|0D                                              ATE1.
Mon 2021/03/01 15:13:22: Phone does not support enabled echo, it can not work with Gammu!
Mon 2021/03/01 15:13:22: It might be caused by other program using the modem.
Mon 2021/03/01 15:13:22: See <https://wammu.eu/docs/manual/faq/general.html#echo> for help.
Mon 2021/03/01 15:13:22: Init:GSM_TryGetModel failed with error TIMEOUT[14]: No response in specified timeout. Probably the phone is not connected.
Mon 2021/03/01 15:13:22: Entering GSM_SetIncomingSMS
Mon 2021/03/01 15:13:22: Getting available SMS memories
Mon 2021/03/01 15:13:22: SENDING frame type 0x00/length 0x0A/10
Mon 2021/03/01 15:13:22: 41A|54T|2B+|43C|50P|4DM|53S|3D=|3F?|0D                          AT+CPMS=?.

Les logs font référence à https://docs.gammu.org/faq/general.html#echo
La commande : fuser -va /dev/ttyUSB-3G renvoie :

                     UTIL.       PID ACCÈS  COMMANDE
/dev/ttyUSB2:        root       2060 F.... python3

La commande : gammu identify
Erreur à l'ouverture du périphérique : périphérique inconnu, occupé ou problème de permissions.
Ce qui est normal quand raspisms est démarré donc Gammu occupé !
Une fois arrêté le gammu identify indique :

Périphérique       : /dev/ttyUSB-3G
Fabricant            : Huawei
Modèle              : E3531 (E3531)
Firmware             : 22.521.35.00.1217
IMEI                 : 861143035493085
SIM IMSI             : 208014706668400

La commande gammu --config /etc/gammurc sendsms TEXT '+33612345678' -text 'texte1234' -validity MAX -autolen '9' renvoie :
Erreur à l'ouverture du périphérique : périphérique inconnu, occupé ou problème de permissions.

La commande gammu-detect

; Fichier de configuration généré par gammu-detect.
; Merci de consulter le manuel de Gammu pour plus d'informations.

[gammu]
device = /dev/ttyS0
name = Téléphone sur le port série 0
connection = at

[gammu1]
device = /dev/ttyUSB0
name = Téléphone sur le port USB série HUAWEIHUAWEI_Mobile
connection = at

[gammu2]
device = /dev/ttyUSB2
name = Téléphone sur le port USB série HUAWEIHUAWEI_Mobile
connection = at

[gammu3]
device = /dev/ttyUSB3
name = Téléphone sur le port USB série HUAWEIHUAWEI_Mobile
connection = at

Error finding Bluetooth adapter: Aucun périphérique de ce type

Je réinitialise Gammu : /usr/sbin/usb_modeswitch -W -v 12d1 -p 155e -R

Take all parameters from the command line


 * usb_modeswitch: handle USB devices with multiple modes
 * Version 2.5.2 (C) Josua Dietze 2017
 * Based on libusb1/libusbx

 ! PLEASE REPORT NEW CONFIGURATIONS !

DefaultVendor=  0x12d1
DefaultProduct= 0x155e

Look for default devices ...
  found USB ID 12d1:155e
   vendor ID matched
   product ID matched
  found USB ID 8564:4100
  found USB ID 0bc2:61b6
  found USB ID 0424:ec00
  found USB ID 0424:9514
  found USB ID 1d6b:0002
 Found devices in default mode (1)
Access device 005 on bus 001
Get the current device configuration ...
Current configuration number is 1
Use interface number 0
 with class 255

USB description data (for identification)
-------------------------
Manufacturer: HUAWEI
     Product: HUAWEI Mobile
  Serial No.: not provided
-------------------------
Warning: no switching method given. See documentation
Reset USB device .
 Device was reset
-> Run lsusb to note any changes. Bye!

Je lance lsusb mais rien de mieux !

La commande ps aux | grep gammu

root      1691  0.0  0.0   1940   396 ?        S    15:53   0:00 sh -c /usr/share/raspisms/bin/gammu_get_unread_sms.py '/etc/gammurc' 2>&1
root      1692  6.0  1.2  36800 12924 ?        S    15:53   0:00 python3 /usr/share/raspisms/bin/gammu_get_unread_sms.py /etc/gammurc
root      1694  0.0  0.0   7368   556 pts/0    S+   15:53   0:00 grep gammu

A force de redémarrages, réinstallations, retrait manuel du dongle..., cela finit par fonctionner sans identifier la nature du problème...
D'ailleurs en finissant d'écrire ces lignes, tout se remet à marcher !
Affaire à suivre ;)

[FredMa01]

Je ne sais pas s'il y a un lien avec ce pb de téléphone Gammu ou s'il s'agit d'un autre souci mais, je réalise que même quand le téléphone marche bien en émission/réception, il arrive que les envois de commandes ne marchent plus.
C'est le cas actuellement.
Je me retrouve donc comme dans l'issue #154 :
Il semble y avoir un pb d'encodage :

Receive message : {"at":"2021-03-01 16:18:50","text":"{\"login\":\"[email protected]\",\"password\":\"xxxxxxxxxx\",\"command\":\"stoppi3\"}\u0000e","origin":"+3312345678"} [] []
Receive message : {"at":"2021-03-01 16:19:23","text":"{\"login\":\"[email protected]\",\"password\":\"xxxxxxxxxx\",\"command\":\"sms\"}\u00003","origin":"+3312345678"} [] []

L'ajout de la ligne file_put_contents(PWD_DATA . '/tst.txt', print_r($decode_message, true)); après la ligne 88 du fichier controllers\internals\Command.php , modifie le fichier /usr/share/raspisms/data/tst.txt mais celui-ci reste vide !

[OsaAjani]

Pour moi il faut bien distinguer le cas des commandes, qui viens à priori d'un problème d'encodage, et le cas des problèmes d'envoi/reception des messages.

Pour les problèmes d'envoi/reception, ce qui me choque c'est de voir que tu as deux script /usr/share/raspisms/bin/gammu_get_unread_sms.py '/etc/gammurc' qui tournent en même temps, et sur le même fichier de conf gammu. Ça ne devrait pas arriver et cela va forcément créer des conflits entre les deux scripts, et donc des blocages.

Pour le problème des commandes, je ne vois pas comment la ligne file_put_contents peut créer un fichier vide, essaie de replacer la partie $decode_message par 'toto' pour voir si ça inscrit bien toto dans le fichier.

[OsaAjani]

Je rajoute au passage que je te conseils d'utiliser un autre fichier que /etc/gammurc pour les téléphones à créer au sein de RaspiSMS. Notamment pour éviter les conflits si tu créer plusieurs téléphones, ou si un service gammu démarre. Dans la documentation sur l'utilisation de gammu avec RaspiSMS, je conseils de créer un fichier /etc/gammu_<un_id_unique>.rc pour chaque téléphone.

[FredMa01]

J'ai changé de fichier de config pour le téléphone. Je supprime l'ancien téléphone, crée un nouveau avec ce nouveau fichier puis relance le service raspisms :

ps aux | grep gammu
root      9969  0.0  0.0   1940   376 ?        S    13:12   0:00 sh -c /usr/share/raspisms/bin/gammu_get_unread_sms.py '/etc/gammu_raspi.rc' 2>&1
root      9970 10.0  1.3  36800 13132 ?        S    13:12   0:00 python3 /usr/share/raspisms/bin/gammu_get_unread_sms.py /etc/gammu_raspi.rc

J'ai toujours les 2 scripts !

[FredMa01]

Je te confirme que 'toto' s'écrit bien dans le fichier !

/* Fred */
$decode_message= 'toto';
file_put_contents(PWD_DATA . '/tst.txt', print_r($decode_message, true));

[OsaAjani]

Pour les deux script j'ai trouvé l'origine, en fait c'est normal, le premier script déclenche l'appel du deuxième, c'est juste la façon dont php execute une commande unix, donc ça n'est pas ça qui pose le problème.

Pour le cas du fichier tst.txt qui est vide je viens de me rendre compte que print_r n'affiche pas les valeures NULL comme var_dump, donc c'est bien que le fichier ne peut pas être décodé comme un JSON valide, à cause du caractère mal encodé \u00003. Ce caractère me fait penser ou bien à un encodage python bizarre, ou bien à un encodage UTF-16 converti en code JSON, mais que PHP n'arrive pas à décoder. Ça reste à creuser donc pour voir comment se débarasser du problème.

[ebardoul]

Est-ce que le problème n'est pas que même si on supprime un téléphone Gammu, il y a toujours des démons qui sont lancés à son sujet.
Quand je regarde /var/log/raspisms/daemons.log j'ai ceci :
[2022-12-12T09:20:59.735338+01:00] RaspiSMS Daemon Phone 8.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:21:12.834696+01:00] RaspiSMS Daemon Phone 2.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:21:57.896547+01:00] RaspiSMS Daemon Phone 2.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:22:15.848508+01:00] RaspiSMS Daemon Phone 8.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:23:59.528282+01:00] RaspiSMS Daemon Phone 8.INFO: Stopping Phone daemon with pid 2528 [] []
[2022-12-12T09:24:00.601526+01:00] RaspiSMS Daemon Phone 8.INFO: Starting Phone daemon with pid 2582 [] []
[2022-12-12T09:24:12.561608+01:00] RaspiSMS Daemon Phone 2.INFO: Stopping Phone daemon with pid 2533 [] []
[2022-12-12T09:24:13.630292+01:00] RaspiSMS Daemon Phone 2.INFO: Starting Phone daemon with pid 2585 [] []
[2022-12-12T09:24:33.970068+01:00] RaspiSMS Daemon Phone 2.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:24:51.855071+01:00] RaspiSMS Daemon Phone 8.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:26:26.472622+01:00] RaspiSMS Daemon Phone 8.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:26:39.825536+01:00] RaspiSMS Daemon Phone 2.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:28:39.185920+01:00] RaspiSMS Daemon Phone 2.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:28:56.865391+01:00] RaspiSMS Daemon Phone 8.INFO: Error reading received smss : Gammu command return failed. [] []
[2022-12-12T09:29:01.377737+01:00] RaspiSMS Daemon Phone 8.INFO: Stopping Phone daemon with pid 2582 [] []
[2022-12-12T09:29:02.448521+01:00] RaspiSMS Daemon Phone 8.INFO: Starting Phone daemon with pid 2636 [] []
[2022-12-12T09:29:14.443435+01:00] RaspiSMS Daemon Phone 2.INFO: Stopping Phone daemon with pid 2585 [] []
[2022-12-12T09:29:15.509502+01:00] RaspiSMS Daemon Phone 2.INFO: Starting Phone daemon with pid 2638 [] []

Je vois un tas de démons lancés pour des téléphone qui n'existent plus. Puisque seul le N°8 existe. Les autres ont été des essais et comme il est impossible de modifier un téléphone. On est obligé de supprimer le téléphone et d'en créer un nouveau.

En plus il m'a fallut bloquer le démon gammu-smsd qui se lançait automatiquement au démarrage.

Tous ces démons qui cherchent à utiliser la même ressource, ça doit finir par rendre instable la configuration et si on a de la chance, les sms partent, mais si il y a conflit au moment de l'envoi, alors c'est l'échec.