virtualdj / pun_sensor

Prezzi PUN del mese - Home Assistant Integration
MIT License
78 stars 13 forks source link

Cambio tra le fasce orarie non avviene #16

Closed TommasoPino closed 8 months ago

TommasoPino commented 9 months ago

Buongiorno, uso il tuo componente da qualche giorno e volevo prima di tutto ringraziarti per l'ottimo lavoro.

Riscontro però un problema sull'aggiornamento della fascia oraria tra le varie Fx. A volte il sistema manca di cambiare fascia con conseguente sballo dei prezzi generali. Sembra che il sistema usato di schedula non funzioni a dovere. Hai per caso riscontrato lo stesso problema?

Grazie mille e buona giornata

virtualdj commented 9 months ago

A volte il sistema manca di cambiare fascia con conseguente sballo dei prezzi generali. Sembra che il sistema usato di schedula non funzioni a dovere. Hai per caso riscontrato lo stesso problema?

No, sinceramente il cambio di fascia mi sembra funzionare sempre correttamente (anche perché è un mero calcolo che non dipende da API o dati online, quindi estremamente leggero sulla CPU).

Qui uno screenshot appena fatto, puoi controllare col tuo se è diverso.

Schermata Home Assistant

TommasoPino commented 9 months ago

Confermo che è diverso

image

virtualdj commented 9 months ago

Prova ad abilitare i log per l'estensione aggiungendo queste voci a configuration.yaml:

logger:
  default: warning
  logs:
    custom_components.pun_sensor: debug

In questa maniera nel log di Home Assistant dovrebbero essere stampate informazioni in merito. La riga di tuo interesse è quella che inizia con il messaggio Nuova fascia corrente:.

Magari è dovuto alla time-zone del sistema dove esegui Home Assistant? Non credo, mi sembrava di averlo testato in una VM con TZ inglese, ma non si sa mai... sto imparando anch'io 😄

virtualdj commented 9 months ago

Ho riprovato in una VM ed effettivamente il calcolo delle fasce segue il fuso orario impostato in Home Assistant.

Perciò, se per esempio ho impostato la timezone di Santiago (GMT-3) e in Italia sono le 21:05 (F2), in realtà la fascia verrà identificata con l'ora di Santiago (16:05 a causa dell'ora legale) quindi F1. Dopodiché il prossimo aggiornamento verrà impostato per la fascia F2 (transizione F1 > F2) alle ore 19, ma per Santiago sono 3 ore (16 > 19) mentre in Italia sarebbero 2 (21 > 23) quindi questo sballa tutto!

Evidentemente non avevo considerato questo problema durante lo sviluppo; credo sia opportuno impostare la timezone fissa sull'ora dell'Italia per quanto riguarda il calcolo delle fasce orarie, tanto comunque queste sono tipiche italiane, giusto?

TommasoPino commented 9 months ago

image

il problema è che non è che non avvenga all'orario spaccato (sto in italia con il fuso di Roma) ma che avviene ad orari random (il cambio alle 14:06 è dovuto al riavvio schedulato di HA)

Io ho un'altra entità per le fasce orarie che cambio con un select per mezzo di una automazione che funziona perfettamente (non tengo conto del festivo al di fuori della domenica ma è un problema marginale)

# configuration.yaml
utility_meter:
   rete_montly_energy:
     source: sensor.generale_casa_energy
     cycle: monthly
     tariffs:
       - F1
       - F2
       - F3
   casa_monthly_energy:
     source: sensor.energia_domestica
     cycle: monthly
     tariffs:
       - F1
       - F2
       - F3
# automation.yaml
- id: '1670751116400'
  alias: Tariffe energetiche
  description: ''
  trigger:
  - platform: time
    id: '7'
    at: '7:00:00'
    variables:
      tariff: F2
  - platform: time
    id: '8'
    at: '8:00:00'
    variables:
      tariff: F1
  - platform: time
    id: '19'
    at: '19:00:00'
    variables:
      tariff: F2
  - platform: time
    id: '23'
    at: '23:00:00'
    variables:
      tariff: F3
  condition: []
  action:
  - choose:
    - conditions:
      - condition: trigger
        id: '7'
      sequence:
      - condition: time
        weekday:
        - mon
        - tue
        - wed
        - thu
        - fri
        - sat
      - service: select.select_option
        target:
          entity_id: select.rete_montly_energy
        data:
          option: '{{ tariff }}'
      - service: select.select_option
        target:
          entity_id: select.casa_monthly_energy
        data:
          option: '{{ tariff }}'
    - conditions:
      - condition: trigger
        id: '8'
      sequence:
      - condition: time
        weekday:
        - mon
        - tue
        - wed
        - thu
        - fri
      - service: select.select_option
        data:
          option: '{{ tariff }}'
        target:
          entity_id: select.rete_montly_energy
      - service: select.select_option
        data:
          option: '{{ tariff }}'
        target:
          entity_id: select.casa_monthly_energy
    - conditions:
      - condition: trigger
        id: '19'
      sequence:
      - condition: time
        weekday:
        - mon
        - tue
        - wed
        - thu
        - fri
      - service: select.select_option
        target:
          entity_id: select.rete_montly_energy
        data:
          option: '{{ tariff }}'
      - service: select.select_option
        target:
          entity_id: select.casa_monthly_energy
        data:
          option: '{{ tariff }}'
    - conditions:
      - condition: trigger
        id: '23'
      sequence:
      - service: select.select_option
        target:
          entity_id: select.rete_montly_energy
        data:
          option: '{{ tariff }}'
      - service: select.select_option
        target:
          entity_id: select.casa_monthly_energy
        data:
          option: '{{ tariff }}'
  mode: single
  initial_state: true
virtualdj commented 9 months ago

Sinceramente non ha spiegazione l'esecuzione ad orari random perché uso proprio la funzione di schedulazione all'orario "spaccato" (async_track_point_in_time).

Puoi inviare i log, abilitandi come suggerito in precedenza?

virtualdj commented 8 months ago

Ciao, prova la nuova versione taggata come v0.4.0 e vediamo se ti capita lo stesso.

g1za commented 8 months ago

Anche io avevo notato che il cambio di fasce mi rimaneva indietro; avevo quindi creato un'automazione che mi aggiorna le entità al passaggio di fascia (00:00, 7:00, 8:00, 19:00, 23:00) in modo da averlo sempre corretto. Vediamo con la nuova versione. Grazie!

virtualdj commented 8 months ago

@g1za @TommasoPino Nel mio caso il cambio di fascia ha sempre funzionato perfettamente. Se per cortesia mi fate avere i log (come descritto nel paragrafo "in caso di problemi" del README) provo a capirne la causa, se la versione v0.4.0 non avesse già risolto.

virtualdj commented 8 months ago

Giusto per farvi capire, questo è il log nel mio sistema di 10 minuti fa (abilitando la funzionalità di debug):

2023-10-23 17:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Mon 23/10/2023 19:00:00 +0200
2023-10-23 17:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Mon 23/10/2023 19:00:00 +0200
2023-10-23 17:00:00.012 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F2 (prossima: Mon 23/10/2023 23:00:00 +0200)

Come si vede l'orario di trigger del cambio fascia è 17:00:00.001 cioè vuol dire spaccato al millisecondo! E questo da un container Docker che gira su un NAS, quindi non con chissà quali prestazioni...

Screenshot cambio fascia

Per questo motivo non riesco a spiegarmi come mai a voi sbagli di così tanto. Spero che i log aiutino a fare luce su questo!

TommasoPino commented 8 months ago

Buonaserq virtualdj, appena riesco ti faccio avere feedback, ho un bimbo piccolo e non ho tanto tempo, mi dispiace.

Il giorno lun 23 ott 2023 alle 19:14 virtualdj @.***> ha scritto:

Giusto per farvi capire, questo è il log nel mio sistema di 10 minuti fa (abilitando la funzionalità di debug):

2023-10-23 17:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Mon 23/10/2023 19:00:00 +0200 2023-10-23 17:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Mon 23/10/2023 19:00:00 +0200 2023-10-23 17:00:00.012 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F2 (prossima: Mon 23/10/2023 23:00:00 +0200)

Come si vede l'orario di trigger del cambio fascia è 17:00:00.001 cioè vuol dire spaccato al millisecondo! E questo da un container Docker che gira su un NAS, quindi non con chissà quali prestazioni...

[image: Screenshot cambio fascia] https://user-images.githubusercontent.com/3251704/277418563-c6f984fd-3ed0-4fb5-a6f3-4762ae0ba617.png

Per questo motivo non riesco a spiegarmi come mai a voi sbagli di così tanto. Spero che i log aiutino a fare luce su questo!

— Reply to this email directly, view it on GitHub https://github.com/virtualdj/pun_sensor/issues/16#issuecomment-1775651301, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFMXQOCYBALTUMS5I3UWS3LYA2QYRAVCNFSM6AAAAAA5BDD62SVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTONZVGY2TCMZQGE . You are receiving this because you were mentioned.Message ID: @.***>

g1za commented 8 months ago

Ciao, Ho aspettato un attimo per verificarne il funzionamento dopo aver disattivato l'automazione. Per ora il comportamento anomalo a me non si sta ripresentando. Lo monitoro ancora un paio di giorni e se ritorna scaricherò i log (per ora non c'è nulla da rilevare). Grazie!

Screenshot 2023-10-23 alle 20 14 07

virtualdj commented 8 months ago

se ritorna scaricherò i log (per ora non c'è nulla da rilevare).

Sì, l'imporante è che attivi già ora la raccolta dei log, perché se la attivi dopo che è successo il problema non verranno scritti. Tanto questa integrazione non è che logghi molto, lo fa solo quando aggiorna i prezzi (quindi 1 volta al giorno) e quando cambia fascia (quindi 4 volte al giorno).

g1za commented 8 months ago

Purtroppo stamattina ho trovato la registrazione bug disattivata :( La riattivo e riprovo stasera/domani (per cronaca verso le 9:20 ho forzato io la fascia corretta)

Screenshot 2023-10-24 alle 09 19 22

g1za commented 8 months ago

Finora il problema non si è più ripresentato. L'altra mattina ho trovato il debug disattivato perché mi si era riavviato HA (ho avuto dei problemi che forse ho risolto riparando il DB). A meno che questo non abbia causato il ritardo di aggiramento... anche se a rigor di logica una volta che il sistema si riavvia dovrebbe aggiornarsi automaticamente anche se l'ora di cambio di fascia è giù passata, no? (un po' come quando lo aggiornavo io in modo forzato).

virtualdj commented 8 months ago

Finora il problema non si è più ripresentato.

Guarda, mi piacerebbe capirne di più ma non riuscendo a simularlo né sul mio sistema principale né sulle virtual machine non saprei dirne le cause. La funzione di scheduling è interna a Home Assistant e può "saltare" solo se lui è bloccato/terminato ovviamente.

A meno che questo non abbia causato il ritardo di aggiramento...

Penso proprio di sì, però è strano che anche TommasoPino abbia lo stesso problema.

a rigor di logica una volta che il sistema si riavvia dovrebbe aggiornarsi automaticamente anche se l'ora di cambio di fascia è giù passata, no?

Sì, quando parte Home Assistant viene aggiornata la fascia e schedulato il cambio fascia successivo. Questo si dovrebbe vedere anche dai log, comunque, se attivati.

g1za commented 8 months ago

Beccato! Ho il log. Screenshot 2023-10-26 alle 08 25 23

home-assistant_pun_sensor_2023-10-26T06-24-42.956Z.log

virtualdj commented 8 months ago

Ho esaminato il log, ma cercando non ho trovato nessuna riga con pun_sensor a parte quella dell'avvio di HA (la terza). Nel mio log, di oggi, dopo le 00:30 tue (che sono GMT quindi le 02:30 italiane) la prima voce è questa:

2023-10-26 05:00:00.003 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Thu 26/10/2023 07:00:00 +0200
2023-10-26 05:00:00.003 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Thu 26/10/2023 07:00:00 +0200
2023-10-26 05:00:00.054 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F2 (prossima: Thu 26/10/2023 08:00:00 +0200)

mentre nel tuo log a quell'ora non c'è assolutamente nulla, quindi il cambio fascia non è stato eseguito. Queste sono le voci vicine a quell'ora nel tuo log:

2023-10-26 04:59:59.984 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback None()
2023-10-26 05:01:54.196 ERROR (MainThread) [custom_components.multiscrape.coordinator] Prezzo zonale domani # Updating failed with exception: Client error '404 Not Found' for url 'https://www.mercatoelettrico.org/It/WebServerDataStore/MGP_Prezzi/20231027MGPPrezzi.xml'
For more information check: https://httpstatuses.com/404
2023-10-26 05:01:54.197 ERROR (MainThread) [custom_components.multiscrape.sensor] Prezzo zonale domani # Prezzo zonale mscr domani 00 # Unable to scrape data: Skipped scraping because data couldn't be updated 
Consider using debug logging and log_response for further investigation.
2023-10-26 05:01:54.197 ERROR (MainThread) [custom_components.multiscrape.sensor] Prezzo zonale domani # Prezzo zonale mscr domani 01 # Unable to scrape data: Skipped scraping because data couldn't be updated 
Consider using debug logging and log_response for further investigation.

Visto che ci sono una marea di errori nel tuo log, mi fa pensare che "intasino" Home Assistant a tal punto che non riesce ad avere il tempo di eseguire altre operazioni (nello specifico, il cambio di fascia) anche se comunque non ha molto senso... perché dovrebbe caso mai eseguirlo in ritardo. Ti è mai capitato di vedere il cambio fascia in ritardo?

Rimane comunque anomalo che tu abbia così tanti errori dovuti all'integrazione multiscrape; proverei un giorno a disabilitarla, così come a sistemare quel template sensor che usa l'espressione '{{(as_timestamp(now())-as_timestamp((states.sensor.p_batt_forecast.last_updated)))/60 > 32 }}'.

Riesci a farmi questo test?

g1za commented 8 months ago

Ciao,

Allora, ti spiego un attimo il motivo di quel casino: uso la tua integrazione perché è magnifica per prendere e calcolare i PUN mesili. Ho poi installato multiscrape perché la uso per recuperare i prezzi zonali per costruirmi quanto mi pagano l'energia elettrica immessa in rete. Gli errori sono dovuti al fatto che fin verso le 13/14 non vengono pubblicati i dati per il giorno seguente e quindi multiscrape si lamenta (o perlomeno ho sempre pensato e capito così). Ho poi dovuto fare un giro strano con un sensore di appoggio perché multiscrape può tenere il valore precedente se il nuovo scraping fallisce, ma se riavvii il sistema e non c'è nulla da scaricare il sensore di multiscrape restituisce not available (o un errore, non ricordo... comunque questa è un'altra storia).

L'ultimo è un template che uso da trigger in un'automazione che ho disabilitato in seguito a disabilitazione di un add-on che forse il mio Pi3 non riesce a reggere (mi crashava HA e ora che l'ho disabilitato non succede più). Avendo disabilitato l'add-on non esiste al momento sensor.p_batt_forecast, da cui l'errore. Per toglierlo potrei spostare l'automazione dalla cartella.

Per riassumere: posso disabilitare multiscrape e tutti i sensori ad esso correlati e spostare le automazioni. Tanto come ti dicavo l'add-on che le usa al momento è disabilitato.

Per quanto riguarda la tua domanda: no, nella mia limitata esperienza se la fascia resta indietro non recupera più a meno di non forzarla a mano. Devo dire che però mi pare succeda solo quando da F3 deve tornare ad un'altra... però potrebbe essere un caso.

Disabilito e provo a recuperare un nuovo log.

Fammi sapere se hai commenti. ;)

g1za commented 8 months ago

Ho esaminato il log, ma cercando non ho trovato nessuna riga con pun_sensor a parte quella dell'avvio di HA (la terza). Nel mio log, di oggi, dopo le 00:30 tue (che sono GMT quindi le 02:30 italiane) la prima voce è questa:

Domanda: ma non stiamo nello stesso fuso orario? Il mio HA è impostato con orario su Roma

virtualdj commented 8 months ago

posso disabilitare multiscrape e tutti i sensori ad esso correlati e spostare le automazioni. Tanto come ti dicavo l'add-on che le usa al momento è disabilitato.

Sì, ma basta anche solo per 1 giorno, per capire se disabilitandolo la mia integrazione funziona; poi, il giorno successivo, riabilitando multiscrape e vedendo se così la mia si pianta di nuovo.

Vorrei solo capire se è il Pi3 che non ce la fa ad eseguire il task perché "troppo impegnato" a richidere dati dalla rete che non arriveranno (se noti nel log le richieste e gli errori sono molto frequenti, almeno nell'orario in cui c'è il cambio fascia). Secondo me non ha molto senso che la funzione non venga chiamata, semmai lo dovrebbe fare in ritardo... però sono troppo alle prime armi per capirlo. Ho aperto un thread sulla community HA, ma tanto dubito mi risponderanno... 😞

se la fascia resta indietro non recupera più

Ha senso, perché la funzione è "progressiva". Quando si schedula il cambio fascia ed è "l'ora corretta" la funzione viene chiamata, cambia il valore della fascia calcolando qual è la prossima ora di cambio e questa viene schedulata di nuovo per la prossima esecuzione.

Se l'esecuzione "n" fallisce perché non viene chiamata (come nel tuo caso) allora l'esecuzione "n + 1" non potrà mai essere richiamata, perché non è stata schedulata! Il problema è che non so come altro fare... ed è quello che ho scritto nella domanda nella community.

a meno di non forzarla a mano

In questo caso infatti viene richiamata nuovamente la routine di avvio dell'integrazione che aggiorna il valore e schedula l'aggiornamento successivo. Quindi tutto come da programma... a parte la mancata esecuzione di async_track_point_in_time!

però mi pare succeda solo quando da F3 deve tornare ad un'altra... però potrebbe essere un caso.

Perché secondo me a quell'ora, cioè di notte, hai qualche altro job che inchioda HA a tal punto che non riesce più ad eseguire la funzione schedulata. Infatti nei tuoi log non c'è la riga:

XXXX-XX-XX XX:00:00.0XX INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente ...

Domanda: ma non stiamo nello stesso fuso orario?

Sì e comunque con l'ultima versione ho sistemato quella cosa. Anche se imposti in HA il fuso delle Fiji l'aggiornamento delle fasce avviene sempre all'orario italiano. Il log di HA però mi pare di vedere che è sempre espresso in UTC, quindi il cambio fascia delle 7 italiane lo dovresti vedere alle 5 nel log (vedi mio più sopra e nota come è all'orario "spaccato" al millisecondo, quasi).

virtualdj commented 8 months ago

Ah altra cosa interessante che noto dai tuoi log è che all'avvio dovresti avere la voce Coordinator inizializzato quasi subito (io ce l'ho sempre) mentre nel tuo non lo vedo. Aggiungo anche che dopo il riavvio di Home Assistant, dovrebbe esserci anche questa voce nel log:

2023-10-26 16:18:22.689 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration pun_sensor which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
...
2023-10-26 16:18:29.885 DEBUG (MainThread) [custom_components.pun_sensor] Coordinator inizializzato
g1za commented 8 months ago
2023-10-26 16:18:22.689 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration pun_sensor which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

Questa l'ho vista anche io l'altro giorno, può essere che non sia nel log perché l'ho attivato dopo il riavvio (anche perché mi pare - mi è capitato - che se lo attivo e poi riavvio me lo trovo disattivato).

virtualdj commented 8 months ago

L'ho provato su una VM e la modalità di debug rimane attiva se riavvii Home Assistant. Comunque mi riferivo alla linea Coordinator inizializzato che manca e che dovrebbe apparire subito dopo l'altra... a meno che HA non sia impegnato pure in quel momento!

g1za commented 8 months ago

Provo ancora allora e vediamo se resta attivo, così hai tutto

g1za commented 8 months ago

Solo questo non riesco ad eliminare commentando i sensori e vorrei evitare di disinstallare proprio l'integrazione multiscrape...

Scraper_noname_0 # Updating failed with exception: Invalid type for url. Expected str or httpx.URL, got <class 'NoneType'>: None

virtualdj commented 8 months ago

Se i log di multiscrape appaiono ogni tanto (anche ogni minuto per dire) non credo affatto sia un problema. Ma anziché commentare i sensori non fai prima a disabilitare multiscrape? Disabilitare, non disinstallare.

virtualdj commented 8 months ago

Comunque mi riferivo alla linea Coordinator inizializzato che manca e che dovrebbe apparire subito dopo l'altra

Ho fatto un'altra prova nella VM e penso che anche questo sia parte del problema. Se non c'è quella riga, significa che l'integrazione non è inizializzata, quindi non può effettuare nessun cambio fascia.

Tuttavia, nel mio caso l'unico modo di non farla apparire è quella di disabilitare l'integrazione, ma così facendo i valori dei sensori diventano Non disponibile quindi non mi spiego la tua situazione...

g1za commented 8 months ago

Ho controllato ora e si è ripresentato nonostante avessi disattivato gran parte delle cose come hai visto. Però sono su cellulare e non sono riuscito a scaricare il log che è andato perso. Riprovo nei prossimi giorni. Tanto ricapita.

IMG_3249

virtualdj commented 8 months ago

non sono riuscito a scaricare il log che è andato perso

Non dovrebbe andare perduto, perché è lo stesso di Home Assistant. Se vai in Impostazioni > Sistema > Registri e carichi quello completo è ancora lì e puoi scaricarlo.

In pratica il pulsante nell'estensione serve principalmente per far apparire le relative voci nel log di Home Assistant.

g1za commented 8 months ago

IMG_3250

virtualdj commented 8 months ago

@g1za Scusa ma non riesco a vedere il problema in questa schermata che hai postato (e anche nella precedente). Il cambio in F2 è avvenuto alle 07:00:00 quindi mi pare perfetto, no? Oggi è sabato, quindi è corretto che la fascia rimanga F2.

g1za commented 8 months ago

Hai ragione

rayxxxxx commented 8 months ago

Ciao, ho lo stesso problema. Utilizzo questa integrazione da un mese e in questi ultimi due giorni ho riscontrato lo stesso problema. Per esempio oggi la F1 non si è mai impostata e alle 19 è passato da F3 a F2.

virtualdj commented 8 months ago

Ciao @rayxxxxx, non è che io non vi creda, anzi se posso sistemare sono ben felice di farlo. Il problema è che se non postate i log non ho proprio idea di dove sbattere la testa... e come vedete anche nel post della community di Home Assistant non mi hanno nemmeno considerato (come ampiamente previsto dopotutto, vedi sopra)!

Nel mio piccolo posso dirti che sul mio sistema non si è mai e dico mai impiantato neppure una volta, quindi non riuscendo a simularlo dovreste mandarmi voi i dati...

Registro

rayxxxxx commented 8 months ago

@virtualdj non avevo attivato il debug ed in un mese che il tuo progetto gira sul mio sistema non si era mai verificato quindi ne sono rimasto sorpreso. Attiverò il log come hai indicato e vediamo se succede di nuovo. L'unica nota che posso fornire al momento è che il problema è insorto dopo che ieri mattina ho aggiornato l'integrazione con l'ultima versione.

virtualdj commented 8 months ago

è insorto dopo che ieri mattina ho aggiornato l'integrazione con l'ultima versione

😢 e io che speravo che questa invece risolvesse, grazie al fix della timezone

g1za commented 8 months ago

Appena si ripresenta il problema allego il log, se prima non arriva qualcun altro. Per ora più nulla.

rayxxxxx commented 8 months ago

Il comportamento in questi due giorni non ha evidenziato anomalie:

@virtualdj una domanda: la fascia corrente per il passaggio da uno stato all'altro ha bisogno di internet per funzionare correttamene oppure no?

virtualdj commented 8 months ago

ieri tutto il giorno fascia su F3 che è corretto visto il giorno festivo

Esatto. Bene!

Continuerò a mantenere il log attivo e se dovessero evidenziarsi anomalie cercherò di fornire quanti più dettagli possibili

Sì, grazie, tanto non è che scriva molto nel log quindi non occupa spazio. Speriamo che se ricapita si riesca a capire le cause, perché dai log che ho visto sopra mancava sempre del tutto il trigger dell'esecuzione del cambio fascia, il che mi fa pensare che sia qualcosa che tiene Home Assistant impegnato e non fa eseguire la routine schedulata.

Se questa non viene eseguita, poi non si aggiorna più perché non c'è un controllo (e non mi risulta si possa fare...) se c'è qualcosa di schedulato oppure no. Mi piacerebbe che mi rispondessero, ma finora non è successo... e nemmeno posso aprire una issue sulla core di Home Assistant, visto che al momento non sappiamo ancora replicare il problema.

Di certo non ho idee di come altro fare, mi pare che il procedimento che ho seguito sia corretto infatti nel mio sistema non ha mai perso nulla. Ma se a voi capita, qualcosa di diverso ci deve essere e dobbiamo tentare di capirlo.

la fascia corrente per il passaggio da uno stato all'altro ha bisogno di internet per funzionare correttamene oppure no?

No, non serve Internet. Se hai Internet giù andrà in errore il download dei prezzi all'orario schedulato (e che poi dovrebbe riprovare dopo alcuni minuti fino a 2 ore per poi desistere e riprovare il giorno successivo, cosa che si vede dai log) ma la fascia è indipendente e comunque viene aggiornata essendo basata solo sull'ora di Home Assistant.

rayxxxxx commented 8 months ago

Sfortunatamente oggi non ha aggiornato la fascia ed è fermo a F3. Nel log non vedo tracce dopo quella delle letture dei prezzi di questa notte (come da programma):

2023-11-02 14:36:42.170 DEBUG (MainThread) [custom_components.pun_sensor] Coordinator inizializzato (con 'usa dati reali' = True). 2023-11-02 14:36:42.171 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Thu 02/11/2023 14:36:42 +0100 2023-11-02 14:36:42.171 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Thu 02/11/2023 14:36:42 +0100 2023-11-02 14:36:42.198 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F1 (prossima: Thu 02/11/2023 19:00:00 +0100) 2023-11-02 14:36:42.198 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-02 14:36:57.117 DEBUG (MainThread) [custom_components.pun_sensor] 2 file trovati nell'archivio (20231101MGPPrezzi.xml, 20231102MGPPrezzi.xml). 2023-11-02 14:36:57.133 DEBUG (MainThread) [custom_components.pun_sensor] Numero di dati: 48, 11, 5, 32 2023-11-02 14:36:57.133 DEBUG (MainThread) [custom_components.pun_sensor] Valori PUN: 0.10454680770833334, 0.14306135454545454, 0.127722, 0.0876863084375 2023-11-02 14:36:57.133 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-02 14:36:57.134 DEBUG (MainThread) [custom_components.pun_sensor] Prossimo aggiornamento web: 03/11/2023 01:00:00 +0100 2023-11-02 19:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Thu 02/11/2023 19:00:00 +0100 2023-11-02 19:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Thu 02/11/2023 19:00:00 +0100 2023-11-02 19:00:00.008 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F2 (prossima: Thu 02/11/2023 23:00:00 +0100) 2023-11-02 19:00:00.008 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-02 23:00:00.000 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Thu 02/11/2023 23:00:00 +0100 2023-11-02 23:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Thu 02/11/2023 23:00:00 +0100 2023-11-02 23:00:00.014 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Fri 03/11/2023 07:00:00 +0100) 2023-11-02 23:00:00.014 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-03 01:00:13.599 DEBUG (MainThread) [custom_components.pun_sensor] 3 file trovati nell'archivio (20231101MGPPrezzi.xml, 20231102MGPPrezzi.xml, 20231103MGPPrezzi.xml). 2023-11-03 01:00:13.612 DEBUG (MainThread) [custom_components.pun_sensor] Numero di dati: 72, 22, 10, 40 2023-11-03 01:00:13.612 DEBUG (MainThread) [custom_components.pun_sensor] Valori PUN: 0.09541718611111111, 0.12020254954545455, 0.120124, 0.07560853275 2023-11-03 01:00:13.612 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-03 01:00:13.613 DEBUG (MainThread) [custom_components.pun_sensor] Prossimo aggiornamento web: 04/11/2023 01:00:00 +0100

2023-11-03 02:08:23.822 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration pun_sensor which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

2023-11-03 02:08:38.042 DEBUG (MainThread) [custom_components.pun_sensor] Coordinator inizializzato (con 'usa dati reali' = True). 2023-11-03 02:08:38.043 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Fri 03/11/2023 02:08:38 +0100 2023-11-03 02:08:38.043 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Fri 03/11/2023 02:08:38 +0100 2023-11-03 02:08:38.213 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Sat 04/11/2023 07:00:00 +0100) 2023-11-03 02:08:38.214 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-03 02:08:59.000 WARNING (MainThread) [custom_components.pun_sensor] Errore durante l'aggiornamento via web, nuovo tentativo tra 1 minuto. Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 1155, in _create_direct_connection hosts = await asyncio.shield(host_resolved) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 874, in _resolve_host addrs = await self._resolver.resolve(host, port, family=self._family) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/resolver.py", line 33, in resolve infos = await self._loop.getaddrinfo( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 867, in getaddrinfo return await self.run_in_executor( ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, **self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/socket.py", line 962, in getaddrinfo for res in _socket.getaddrinfo(host, port, family, type, proto, flags): ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ socket.gaierror: [Errno -3] Try again

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/config/custom_components/pun_sensor/init.py", line 292, in update_pun await self._async_update_data() File "/config/custom_components/pun_sensor/init.py", line 163, in _async_update_data async with self.session.get(LOGIN_URL) as response: File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 1141, in aenter self._resp = await self._coro ^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 536, in _request conn = await self._connector.connect( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 540, in connect proto = await self._create_connection(req, traces, timeout) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 901, in _createconnection , proto = await self._create_direct_connection(req, traces, timeout) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 1169, in _create_direct_connection raise ClientConnectorError(req.connection_key, exc) from exc aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host www.mercatoelettrico.org:443 ssl:default [Try again] 2023-11-03 02:10:04.265 DEBUG (MainThread) [custom_components.pun_sensor] 3 file trovati nell'archivio (20231101MGPPrezzi.xml, 20231102MGPPrezzi.xml, 20231103MGPPrezzi.xml). 2023-11-03 02:10:04.278 DEBUG (MainThread) [custom_components.pun_sensor] Numero di dati: 72, 22, 10, 40 2023-11-03 02:10:04.278 DEBUG (MainThread) [custom_components.pun_sensor] Valori PUN: 0.09541718611111111, 0.12020254954545455, 0.120124, 0.07560853275 2023-11-03 02:10:04.278 DEBUG (MainThread) [custom_components.pun_sensor] Manually updated pun_sensor data 2023-11-03 02:10:04.279 DEBUG (MainThread) [custom_components.pun_sensor] Prossimo aggiornamento web: 04/11/2023 01:00:00 +0100

virtualdj commented 8 months ago

@rayxxxxx OK, già qualcosa di interessante. Il mio log:

2023-11-02 22:00:00.002 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Thu 02/11/2023 23:00:00 +0100
2023-11-02 22:00:00.002 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Thu 02/11/2023 23:00:00 +0100
2023-11-02 22:00:00.025 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Fri 03/11/2023 07:00:00 +0100)
### cut ###
2023-11-03 06:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Fri 03/11/2023 07:00:00 +0100
2023-11-03 06:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Fri 03/11/2023 07:00:00 +0100
2023-11-03 06:00:00.013 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F2 (prossima: Fri 03/11/2023 08:00:00 +0100)

Il tuo log:

2023-11-02 23:00:00.000 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Thu 02/11/2023 23:00:00 +0100
2023-11-02 23:00:00.001 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Thu 02/11/2023 23:00:00 +0100
2023-11-02 23:00:00.014 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Fri 03/11/2023 07:00:00 +0100)
### cut ###
2023-11-03 02:08:23.822 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration pun_sensor which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-11-03 02:08:38.042 DEBUG (MainThread) [custom_components.pun_sensor] Coordinator inizializzato (con 'usa dati reali' = True).
2023-11-03 02:08:38.043 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente sistema: Fri 03/11/2023 02:08:38 +0100
2023-11-03 02:08:38.043 DEBUG (MainThread) [custom_components.pun_sensor] Ora corrente fuso orario italiano: Fri 03/11/2023 02:08:38 +0100
2023-11-03 02:08:38.213 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Sat 04/11/2023 07:00:00 +0100)

A parte il fatto che mi piacerebbe capire come mai ti si è riavviato Home Assistant alle 02:08 di oggi (magari se controlli il log completo in Sistema > Registri è scritto?) si nota come subito dopo il riavvio l'integrazione venga caricata, infatti c'è la riga:

2023-11-03 02:08:38.042 DEBUG (MainThread) [custom_components.pun_sensor] Coordinator inizializzato (con 'usa dati reali' = True).

Tuttavia, e qui sta il problema, nonostante la fascia sia riconosciuta correttamente come F3 viene identificata come sbagliata la prossima:

2023-11-03 02:08:38.213 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Sat 04/11/2023 07:00:00 +0100)

Qui sta l'errore, Avrebbe dovuto essere invece:

2023-11-03 02:08:38.213 INFO (MainThread) [custom_components.pun_sensor] Nuova fascia corrente: F3 (prossima: Fri 03/11/2023 07:00:00 +0100)

In sostanza ha "saltato" un giorno. Fammici dare un'occhiata, vediamo cosa riesco a capire... Nel frattempo se mi chiarisci come mai si è riavviato Home Assistant sarebbe utile.

g1za commented 8 months ago

@virtualdj mi faccio un promemoria e stasera provo a riavviare dopo le 23 e prima delle 00. Se ricordi a me succedeva quando mi crashava HA per via di risorse limitate e ho notato che capitava sempre (o quasi) con il passaggio di fascia F3 che non cambiava con il giorno nuovo. Non servirà a niente ma non vorrei fosse qualcosa legato a riavvio e cambio di data... sai mai

virtualdj commented 8 months ago

Ho trovato!!! È proprio questo il problema, un bug del codice che si verifica solo quando si riavvia HA tra le ore 0.00 e le 7.00 di un giorno feriale; essendo che il mio sistema non si riavvia mai, il bug non lo notavo.

A breve fix risolutivo. Grazie a tutti!

rayxxxxx commented 8 months ago

@virtualdj Il riavvio è legato ad un problema che ho da quando Home Assistant sfrutta la connessione tramite wifi e non tramite cavo. Mi spiego meglio. Ho appurato che per qualche ragione, a me sconosciuta, capita che con il WiFi Home Assistant perda la connessione per cui, per ovviare, ho predisposto un'automazione che, ogni qualvolta rileva la mancanza di connessione, riavvia il sistema e in questo modo si ristabilisce la connessione. Lo so che è un brutto workaround ma le mie conoscenze tecniche non vanno oltre :-)

g1za commented 8 months ago

Ho trovato!!! È proprio questo il problema, un bug del codice che si verifica solo quando si riavvia HA tra le ore 0.00 e le 7.00 di un giorno feriale; essendo che il mio sistema non si riavvia mai, il bug non lo notavo.

A breve fix risolutivo. Grazie a tutti!

@virtualdj Ah ottimo. Stavo pensando di rispondere che forse era meglio provare a riavviare dopo le 00 visto il comportamento rilevato dal log di @rayxxxxx ma hai già individuato!

virtualdj commented 8 months ago

Appena eseguito il push della versione 0.4.1 che dovrebbe risolvere definitivamente il problema. Aggiornate e riavviate HA (o anche solo l'integrazione volendo).

TommasoPino commented 8 months ago

Confermo il funzionamento perfetto. Grazie mille :)

virtualdj commented 8 months ago

Grazie a voi, tutti quanti, per avermi fatto notare il bug invece!