Saturation des journaux avec l'erreur « hci0: sending frame failed (-19) »

Bonjour,

Depuis quelques temps, les journaux de mon PC Jeedom principal sont saturés par le message d’erreur suivant que je vois plusieurs fois par minute :

[sam. janv. 27 11:32:14 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:32:29 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:32:44 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:32:59 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:33:14 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:33:29 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:33:44 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:33:59 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:34:14 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:34:29 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:34:44 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:34:59 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. janv. 27 11:35:14 2024] Bluetooth: hci0: sending frame failed (-19)

Sur ce PC, j’ai le BT interne en hci1 pour le plugin BLEA et une clé BT USB en hci0 pour le plugin « phone_detection ».

Et j’ai exactement le même problème de saturation des journaux sur mon second PC qui est un Jeedom déporté sur lequel j’ai configuré une antenne BT pour le plugin « phone_detection » (mais pas de plugin BLEA !).

Dans le log du plugin, je ne vois rien de spécial. En voici un extrait :

[2024-01-27 11:34:34]DEBUG : This is a heartbeat from antenna local version=2.2.2 alive=1
[2024-01-27 11:35:02]DEBUG : computePresence = 0
[2024-01-27 11:35:02]DEBUG : computePresence = 0
[2024-01-27 11:35:02]DEBUG : computePresence = 1
[2024-01-27 11:35:02]DEBUG : computePresence = 1
[2024-01-27 11:35:02]DEBUG : [Alarme][Tél blbb]-->0
[2024-01-27 11:35:02]DEBUG : [Alarme][Tél kblkjbkj]-->0
[2024-01-27 11:35:02]DEBUG : [Alarme][Tél kblkbj]-->1
[2024-01-27 11:35:02]DEBUG : [Alarme][Tél lblkjb]-->1
[2024-01-27 11:35:02]DEBUG : updateGlobalDevice: state=1/nb1=2/nbDevices=4
[2024-01-27 11:35:04]DEBUG : This is a heartbeat from antenna local version=2.2.2 alive=1
[2024-01-27 11:35:09]INFO : Update device status (0) from antenna local for [Alarme][Tél jblkbjlj]
[2024-01-27 11:35:09]INFO : Update value from 0 to 0 for [Alarme][Tél lkjblkjb][Etat_local]
[2024-01-27 11:35:09]DEBUG : computePresence = 0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél jbkklj]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél lkbkjb]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél lbjhlkjb]-->1
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél lbjlkjb]-->1
[2024-01-27 11:35:09]DEBUG : updateGlobalDevice: state=1/nb1=2/nbDevices=4
[2024-01-27 11:35:09]INFO : Update device status (0) from antenna local for [Alarme][Tél ljkblkjb]
[2024-01-27 11:35:09]INFO : Update value from 0 to 0 for [Alarme][Tél lkjblkjb][Etat_local]
[2024-01-27 11:35:09]DEBUG : computePresence = 0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél mkjbnmkj]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél kjblmkjb]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél kjblkjb]-->1
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél kljblkjb]-->1
[2024-01-27 11:35:09]DEBUG : updateGlobalDevice: state=1/nb1=2/nbDevices=4
[2024-01-27 11:35:09]INFO : Update device status (1) from antenna local for [Alarme][Tél mjblkjb]
[2024-01-27 11:35:09]INFO : Update value from 1 to 1 for [Alarme][Tél mkjblkjb][Etat_local]
[2024-01-27 11:35:09]DEBUG : computePresence = 1
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél kjbnlkjb]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél kbjlkjb]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél klblkjb]-->1
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél jbklb]-->1
[2024-01-27 11:35:09]DEBUG : updateGlobalDevice: state=1/nb1=2/nbDevices=4
[2024-01-27 11:35:09]INFO : Update device status (1) from antenna local for [Alarme][Tél kblkjb]
[2024-01-27 11:35:09]INFO : Update value from 1 to 1 for [Alarme][Tél jkblkjb][Etat_local]
[2024-01-27 11:35:09]DEBUG : computePresence = 1
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél lkjblkjb]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél lkjbkjb]-->0
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél kljblkjb]-->1
[2024-01-27 11:35:09]DEBUG : [Alarme][Tél lkjblkjb]-->1
[2024-01-27 11:35:09]DEBUG : updateGlobalDevice: state=1/nb1=2/nbDevices=4
[2024-01-27 11:35:34]DEBUG : This is a heartbeat from antenna local version=2.2.2 alive=1

Voici ce que j’ai essayé pour tenter de faire avancer le schmilblick :

  • J’ai supprimé l’antenne sur le 2nd PC Jeedom et ce message s’arrête immédiatement.
  • Sur le Jeedom principal, j’ai arrêté complètement le plugin BLEA et rebooté, mais j’ai toujours ces messages d’erreur.
  • J’ai ensuite remplacé ma clé SENA par une Trendnet afin de changer de marque et donc de driver : exactement le même problème.
  • J’ai relancé l’installation des dépendances du plugin « phone_detection », vérifié qu’il était bien à jour lui-même, redémarré le PC : toujours pareil.

Je précise que ce sont deux PC totalement différents (carte mère et proc notamment), tous les deux sous Debian 10 et je n’avais pas ce problème de saturation il y a quelques semaines.

Est-ce que quelqu’un aurait une idée SVP ?

Sous linux tu ne vois à aucun moment un souci avec la clé BT ?

Difficile à dire car quand je regarde les journaux, ils sont remplis de ce message d’erreur, donc le reste est effacé : j’arrive peut-être trop tard pour tomber sur quelque chose d’important encore présent :confused:

Mais quand je lance quelque commandes manuellement pour tester (devices, scan, etc.) ça fonctionne bien et je vois mes périphériques BT environnants sans problème. Sur hci0 comme sur hci1 d’ailleurs.

je ne parle pas des logs jeedom mais bien de debian 10… donc effacé je ne pense pas !
Est-ce que les debian sont à jour ?

Oui je parlais bien aussi des logs de Debian :slight_smile:
Quand je fais un « dmesg », je ne vois rien d’autre que ce message d’erreur en boucle, même avec un filtre sur BT ou bluetooth ou USB.

Mes Debian sont à jour de l’été dernier. Je n’aime pas trop monter en version car à chaque fois j’ai un truc qui déconne et j’y passe 2 ou 3 jours à le refaire marcher (je ne suis pas un pro Linux, loin de là).

Par debian à jour, je ne parle pas de monter de version.
Mais bien un apt update apt upgrade histoire d^'etre sur que debian soit à jour

Une montée de version est fortement déconseillée, on conseille plus un backup jeedom, réinstaller un OS propre, jeedom et restaurer le backup.
Cependant va falloir y penser car debian 10 commence a dater on est a 12 !

Attention cependant, BLEA ne tourne pas sous debian 11 etplus a cause d’une LIB plus maintennue, ce qui fait qu’il faut penser aussi a migrer vers un autre plugin comme mqtt discovery, des tutos sont présents ici, enfin un, celui de Fabrice.

enfin dmsg permet de voir le log courant, mais linux fait un logrotate, donc il faut aller voir le log d’avant avec un tail par exemple

ensuite voir si les clés BT ne sont pas suspendue à un moment pour économiser énergie, j’ai eu le coup, donc il faut supprimer cela. Y a aussi un post la dessus ici

Je vais peut-être tenter un update/upgrade sur une des deux machines (même si c’est quand même bizarre que les deux aient le même message d’erreur), tu as raison, on ne sait jamais …

Je me suis affranchi de BLEA, il est maintenant désactivé : c’est d’ailleurs comme ça que je me suis rendu compte de la saturation des logs, car je voulais les consulter.

Ce n’est pas une mise en veille quelconque des clés, j’en suis certain car le message survient immédiatement après le boot quand le plugin s’est relancé.
De plus ça le fait également si je paramètre le plugin sur le BT interne et pas sur la clé USB.

Je vais fouiller avec tail …

Bon, j’ai fouillé dans les fichiers de log, notamment kernel et syslog : aucun message d’erreur à propos d’USB ou de Bluetooth ou BT en dehors de celui dû au plugin qui se répète sans fin.

Bonjour,

A tester en SSH :

sudo apt remove --purge --auto-remove bluez
sudo reboot

Et enfin :

sudo apt install bluez

Sur les Pi, s’assurer que tout est bien à jour :

sudo apt update && sudo apt full-upgrade -y

Bonjour,

Si apres tous les conseils precedents tu as encore des erreurs, je te conseille d’installer la derniere version du plugin, j’ai fait pas mal de modifications pour n’utiliser que du code natif python et eviter les librairies non supportées.

Pour l’erreur (-19), cela vient du driver bluetooth qui n’arrive parfois pas a gerer la cadence d’envoi des requetes de presence, mais ca n’affecte pas le plugin. Tu devrais voir tes telephones quand ils sont presents.

Je te conseille de ne pas descendre en dessous de 15s pour la frequence de polling quand le telephone est absent. A la maison j’ai 15s et 60s quand le telephone est présent.

Si tu veux verifier si les requetes sont bien envoyées, tu peux utiliser l’outil « btmon »

Benoit

Bonjour à tous et merci pour les idées de correction.
Alors voici ce que j’ai pu faire après une image hardware du disque dur au cas où …

  • apt update/upgrade en full => pas mieux
  • purge et réinstallation bluez => pas mieux
  • le plugin « phone-detection » est bien en dernière version (d’ailleurs je soupçonne ce problème d’être apparu vers décembre, lors de la bascule librairies=>python, mais aucune certitude)
  • les fréquences d’updates sont respectées, en fait je n’ai rien modifié dans la config de base :

Mon problème n’est pas que le plugin dysfonctionne (d’ailleurs au contraire, il marche à peu près correctement), c’est que mes journaux sont saturés par ce message et que je ne vois rien d’autre avec un simple dmesg, il faut aller fouiller dans les fichiers de log « syslog » pour voir un peu du reste :frowning:

Bonjour,

Regardez avec ces commandes :
dmesg -H
ou
dmesg -T

Pressez la barre espace pour aller vers le bas et regardez si l’horodatage vous donne des pistes sur les actions de vos équipements

q pour quitter

Bonjour,

Déjà fait, j’ai même analysé tous les fichiers dans /var/log/ mais je n’ai rien trouvé suggérant un problème de port USB, de clé Bluetooth ni de driver Bluetooth (tant l’interne que celui de la clé USB).

Il n’y avait qu’un problème dans le démarrage du service bluetooth à cause du plugin SAP, je l’ai désactivé hier :

  • /etc/systemd/system/bluetooth.service.d/01-disable-sap-plugin.conf =>
[Service]
ExecStart=
ExecStart=/usr/lib/bluetooth/bluetoothd --noplugin=sap

et le service démarre bien depuis :

xxx@NUNUX1ER:[~]:$ sudo systemctl status bluetooth.service
● bluetooth.service - Bluetooth service
   Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/bluetooth.service.d
           └─01-disable-sap-plugin.conf
   Active: active (running) since Sun 2024-01-28 11:28:51 CET; 1h 59min ago
     Docs: man:bluetoothd(8)
 Main PID: 557 (bluetoothd)
   Status: "Running"
    Tasks: 1 (limit: 4915)
   Memory: 4.8M
   CGroup: /system.slice/bluetooth.service
           └─557 /usr/lib/bluetooth/bluetoothd --noplugin=sap

janv. 28 11:28:50 NUNUX1ER systemd[1]: Starting Bluetooth service...
janv. 28 11:28:50 NUNUX1ER bluetoothd[557]: Bluetooth daemon 5.50
janv. 28 11:28:51 NUNUX1ER systemd[1]: Started Bluetooth service.
janv. 28 11:28:51 NUNUX1ER bluetoothd[557]: Starting SDP server
janv. 28 11:28:51 NUNUX1ER bluetoothd[557]: Excluding (cli) sap
janv. 28 11:28:51 NUNUX1ER bluetoothd[557]: Bluetooth management interface 1.14 initialized

Mais ça n’a pas résolu le problème des erreurs à répétition.

Pourtant mon système, ainsi que Jeedom et tous les plugins sont à jour.
J’ai même poussé le vice jusqu’à forcer les mises à jour de PIP3, puis PIP2, mais pas mieux.

bonjour,

je pense que ta version du bluetooth service n’est pas a jour a cause de Debian 10 (buster)
Sur debian 11 (bullseye), la version de bluetooth est 5.55, et non pas 5.50. Si tu regardes sur internet les patchs et les problemes sur bluez, tu verras que la version stable actuelle est la version 5.66, 5.55 la version « old-stable », et la version 5.50 « old-old-stable » (bluez - Debian Package Tracker).

Sur un raspberry utilise comme antenne, il est tres facile de mettre a jour l’os. Une nouvelle carte SD, une install ‹ debian-11-lite › grace a « raspberry pi manager », et ensuite tu peux utiliser les fonctionnalites du plugin phone_detection pour deployer le code sur la nouvelle antenne. Tu pourras voir rapidement si tu as les meme erreurs dans ton ‹ dmesg ›.

Benoit

Bonjour,

Merci pour le retour.
Le problème c’est que je n’ai pas de Raspberry, mais des PC et ils ne servent pas qu’à Jeedom, donc je ne peux pas réinstaller un nouvel OS dessus, ni l’upgrader sans risques :frowning:

Il va bien falloir penser a mettre a jour tes machines.
Debian buster est EOL depuis Septembre 2022, avec des patchs securite seulement jusqu’en juin 2024.
https://wiki.debian.org/DebianReleases

Benoit

Bonjour à tous,

Alors après une mise à jour totale du système et des paquets vers Debian 11 … suivie de 3 jours de galère à refaire fonctionner tout ce qui tourne sur cette machine, ça n’a strictement rien changé.
Dès que le plugin tourne, j’ai toujours ces fichus messages qui me saturent le log en écrivant plusieurs fois par minute :

dmesg -T

[sam. févr.  3 15:23:08 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. févr.  3 15:23:23 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. févr.  3 15:23:38 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. févr.  3 15:23:53 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. févr.  3 15:24:08 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. févr.  3 15:24:23 2024] Bluetooth: hci0: sending frame failed (-19)
[sam. févr.  3 15:24:38 2024] Bluetooth: hci0: sending frame failed (-19)

Mes divers paquets BT sont bien en dernière version officielle dispo pour Debian 11 :

dpkg --list blue

Souhait=inconnU/Installé/suppRimé/Purgé/H=à garder
| État=Non/Installé/fichier-Config/dépaqUeté/échec-conFig/H=semi-installé/W=attend-traitement-déclenchements
|/ Err?=(aucune)/besoin Réinstallation (État,Err: majuscule=mauvais)
||/ Nom                Version                  Architecture Description
+++-==================-========================-============-==================================================
ii  bluez              5.55-3.1+deb11u1         amd64        Bluetooth tools and daemons
un  bluez-audio        <aucune>                 <aucune>     (aucune description n'est disponible)
ii  bluez-cups         5.55-3.1+deb11u1         amd64        Bluetooth printer driver for CUPS
ii  bluez-firmware     1.2-4                    all          Firmware for Bluetooth devices
ii  bluez-hcidump      5.55-3.1+deb11u1         amd64        Analyses Bluetooth HCI packets
un  bluez-input        <aucune>                 <aucune>     (aucune description n'est disponible)
un  bluez-network      <aucune>                 <aucune>     (aucune description n'est disponible)
ii  bluez-obexd        5.55-3.1+deb11u1         amd64        bluez obex daemon
un  bluez-pan          <aucune>                 <aucune>     (aucune description n'est disponible)
un  bluez-serial       <aucune>                 <aucune>     (aucune description n'est disponible)
ii  bluez-test-scripts 5.55-3.1+deb11u1         all          test scripts of bluez
ii  bluez-tools        2.0~20170911.0.7cb788c-4 amd64        Set of tools to manage Bluetooth devices for linux
un  bluez-utils        <aucune>                 <aucune>     (aucune description n'est disponible)

Et l’OS de la machine sur laquelle j’ai testé cette montée de version est bien à jour (Debian 11.8).


Auriez-vous d’autres idées SVP ?

bonjour,

Je dirai supprime tes 4 telephones du plugin phone_detection et redémarre les deamons (local et distant)
Ajoute 1 de tes 4 telephones, redémarre les daemons (local et distant)
Si pas de message, alors, supprime celui que tu viens d’ajouter, et ajoute en un nouveau, redémarre les daemons (local et distant). Fais ca avec tes 4 telephones pour t’assurer que le problème ne vient pas d’un telephone en particulier.

Si tous fonctionnent comme prevu, alors ajoute en un, redémarre, vérifié, puis un second, redémarre, verifie, … je pense que tu as compris la logique :slight_smile:
Cela permettra de verifier si le problème est lie a la charge.

On voit bien des erreurs toutes les 15 secondes, mais une seule erreur et non pas 4 erreurs pour 4 telephones.

Benoit

Bonjour,

Merci pour les idées.
Malheureusement ça n’a rien changé, dès que je redémarre le démon les erreurs « sending frame failed » surgissent toutes les 15 ou 60 secondes.

Par contre ça m’a donné une autre idée de test, mais sans succès non plus :

  • un seul téléphone configuré et qui est physiquement présent : tjs les erreurs.
  • un seul téléphone configuré et qui est physiquement absent : tjs les erreurs.

Bon, pas moyen de faire cesser ces multitudes de messages encombrant mon log, j’ai donc basculé vers un fonctionnement par un vieux script trouvé ici et adapté à ma sauce :

Depuis quelques jours qu’il tourne, je n’ai plus du tout d’erreurs Bluetooth dans mes logs et ils sont donc à nouveau lisibles.
Dommage de perdre la souplesse d’un plugin, mais je n’ai pas trouvé mieux.