Il debug ed il log di eventi personalizzato con Home Assistant

Quando si scrivono automazioni per Home Assistant, uno degli aspetti più rognosi è il debug. Tra trigger, condition ed action, diverse cose possono andare storte e non tutto viene rilevato dall'impostazione / generale / convalida la configurazione. Tramite quel comando, che conviene eseguire dopo ogni modifica, si controlla essenzialmente la sintassi, ossia la grammatica. Tutto un altro discorso è invece quello della logica, dove gli errori possono essere più difficili da individuare.

Quando gli effetti della nostra automazione non si vedono sappiamo che qualcosa non va, ma dove? È il trigger a non essere "scattato", oppure c'è qualcosa di sbagliato nell'action? Si deve sempre procedere per tentativi, in questi casi, ma è utile avere un'evidenza di qualsiasi tipo che almeno ci dica se l'automazione è partita o no, così da concentrare le nostre attenzioni nel punto giusto e risolvere più facilmente gli errori. Il debug, in sostanza, è quello che ci interessa e non è sempre semplice da fare con gli strumenti nativi di Home Assistant. Le voci di menu Registro e Storico sono molto utili in tal senso, però non ci dicono tutto quello che vogliamo sapere: si limitano essenzialmente ai cambiamenti di stato avvenuti nel tempo. Inoltre questi elenchi contengono tutto, che vuol dire tantissime righe e su hardware poco potenti anche lunghe attese per il reload delle pagine. Tutto ciò rende complicata l'individuazione delle voci di nostro interesse che, ad ogni modo, non sarebbero mai più esplicative di un "automation has ben triggered" o "device turned on/off". Ecco perché durante le fasi di debug delle automazioni sono solito utilizzare un altro strumento: il servizio persistent_notification.

Debug con Persistent Notification e Template

Inserito in sostituzione o in aggiunta nella sezione action, questo genera una notifica statica su Home Assistant che, essendo del tutto nativa, non dipende da altri elementi e scongiura l'eventualità che non funzioni per errori esterni all'automazione. Un esempio del suo utilizzo è il seguente:

automation:
  - alias: Nome automazione
    trigger:
      [..]
    condition:
      [..]
    action:
      - service: persistent_notification.create
        data:
          message: "Messaggio"
          title: "Titolo"

La notifica generata in questo modo ha una serie di vantaggi, ma i più importanti sono due:

  1. possiamo isolarla dal resto, rendendo più semplice la sua identificazione (appare la scheda nella pagina principale di HA con il tasto rimuovi per eliminarla)
  2. possiamo scrivere all'interno quel che vogliamo, anche e soprattutto stati e variabili grazie ai modelli di cui abbiamo già parlato (parte uno, parte due)

Relativamente al secondo punto vi voglio fare un esempio concreto. Tra i dispositivi che uso vi è anche uno Xiaomi Cube che ha tante funzionalità "curiose", tra cui la possibilità di creare automazioni ruotandolo su una superficie. In sostanza nell'evento cube_action si trova anche il tipo rotate che ha nel data i gradi di rotazione, così ho deciso di utilizzarlo come un potenziometro per regolare la luminosità di una plafoniera Yeelight. Definire l'algoritmo con la proporzione tra gradi e quantità di luce da togliere o aggiungere non è stato semplice (ancora non ho trovato la ricetta perfetta), ma senza il debug con le persistent_notification sarebbe impossibile. Ecco un esempio di come l'ho utilizzato in fase di creazione, sfruttando la possibilità del data_template per mostrare variabili:

- service: persistent_notification.create
  data_template:
    message: "Parte da {{ states.light.yeelight_ceiling_studio|int }}, Ruotato di {{ trigger.event.data.action_value }}, Nuovo valore {{ (states.light.yeelight_ceiling_studio.attributes.brightness|int + (trigger.event.data.action_value*2)) | round(0) }}"
    title: "Variazione luce"

Avvertenza: qui ho fatto uso dell'automation templating che non abbiamo ancora spiegato, ma che sarà approfondito nella terza ed ultima parte degli articoli dedicati ai modelli, in uscita a breve.

Questo codice mi generava un messaggio in cui potevo leggere facilmente il valore di luminosità di partenza, l'entità della rotazione applicata al cubo e il nuovo valore di luminosità calcolato di conseguenza. Allo stesso tempo mi ha fatto capire i limiti dell'evento e del dispositivo, che ha un po' di lag e non accetta che si ruoti troppe volte in sequenza. Vedere la notifica con queste info è stato fondamentale non solo per valutare l'efficacia della formula ma anche per capire quando era la luce a non rispondere o il cubo a non far scattare il trigger (cose che possono capitare quando si lavora al codice e si eseguono numerose ricariche).

Log di eventi personalizzato

Quando creo una nuova automazione sono solito iniziare soltanto con il trigger e la notifica. Poi aggiungo la condition, se c'è, e solo alla fine scrivo l'action (qui i concetti base). Completato il tutto, il codice persistent_notification smette di essere utile ma non lo cancello, anche se commentato, visto che potrebbe essere utile di nuovo in futuro (specie nel caso in cui vi sia un template ricco di info come quello dell'esempio precedente). Mi sembrava davvero un peccato non farmene nulla di questi dati e così ho pensato di crearmi un log personalizzato. Home Assistant ha già il suo, ma vale quanto già detto per Registro ed Attività: se siamo noi a decidere cosa scrivere significa che possiamo aggiungere informazioni utili e soprattutto mostrare solo i log degli eventi di rilievo. Volendo si possono benissimo mantenere i log di tutte le automazioni, all'inizio, ma se diventano troppe può essere utile nascondere le più banali, soprattutto quando queste sono ormai esenti da bug e non c'è più la necessità di monitorarle. Comunque sia, ho pensato di salvare questi log in singoli file per ogni giorno, inseriti all'interno di cartelle che riportano l'anno e il mese. Per ottenere questo risultato ho creato uno shell_command chiamato log, inserito alla fine del file configuration.yaml:

shell_command:
  log: /bin/bash -c "[ -d /config/log/$(date +%Y-%m) ] || mkdir /config/log/$(date +%Y-%m); echo '{{ now().strftime("%Y-%m-%d %H:%M:%S") }} {{text}}' >> /config/log/$(date +%Y-%m)/day-$(date +%d).log"

Questo esegue un riga di codice bash contenente due diversi comandi separati dal punto e virgola: il primo crea la cartella /log/anno-mese se non esiste già, il secondo aggiunge una riga con il contenuto della variabile "text" preceduto da un identificativo temporale completo (ovvero: anno-mese-giorno ora-minuti-secondi) nel file nominato "day-giorno.log" e posizionato nella stessa cartella. In sostanza lo shell_command.log così configurato è auto sufficiente, non bisogna prima preparargli la posizione in cui salvare nel file system ed i log saranno facilmente raggiungibili visto che sono salvati all'interno della cartella /config che si usa quotidianamente per amministrare Home Assistant (via SMB, SSH/SFTP). La cosa interessante di questa soluzione sta essenzialmente nella variabile text che gli passeremo dalle automazioni, poiché è quella che conterrà l'informazione utile da salvare per il debug o l'analisi. Quando è del testo semplice si richiama così, direttamente nell'action e in aggiunta gli altri comandi preesistenti:

action:
  - service: quello_che_volete
    [..]
  - service: shell_command.log
    data:
      text: 'Testo che vogliamo visualizzare nel log'

Questo genere di info può essere utile tanto e non quanto, viste le funzioni native di Home Assistant di cui abbiamo già parlato, ma le cose cambiano se iniziamo ad utilizzare i template. Nel caso dell'esempio precedente ecco come la notifica utilizzata per il debug si può spostare nel log:

- service: shell_command.log
  data_template:
    text: >
          Cubo Ruotato di {{ trigger.event.data.action_value }},
          Luce Parte da {{ states.light.yeelight_ceiling4_7c49ebb46a76.attributes.brightness|int }},
          Nuovo valore {{ (states.light.yeelight_ceiling4_7c49ebb46a76.attributes.brightness|int + (trigger.event.data.action_value*2)) | round(0) }}

Dal momento che la scrittura su file è istantanea, potenzialmente si può adoperare il log anche nella fase di debug, ma per le cose più complicate trovo più comoda la notifica visto che ci appare davanti agli occhi senza dover compiere alcuna azione. Vi ricordo che queste e tante altre risorse simili si trovano nel nostro #SmartHome Channel.

Autore:
Maurizio Natali (@simplemal)

Revisore:
Alberto Zamboni (@albyzambo)
Davide (@daxda)

SmartHome Channel

Special Team - I SaggiUtenti del canale #SmartHome presente sul nostro Slack uniti per creare guide e recensioni dedicate all'automazione. Partecipa anche tu entrando nel gruppo effettuando una donazione dal SaggioSupporto.

Commenti controllati Oltre a richiedere rispetto ed educazione, vi ricordiamo che tutti i commenti con un link entrano in coda di moderazione e possono passare diverse ore prima che un admin li attivi. Anche i punti senza uno spazio dopo possono essere considerati link causando lo stesso problema.