esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
290 stars 34 forks source link

on_time often not working #573

Closed Airfranse closed 3 years ago

Airfranse commented 5 years ago

Operating environment/Installation (Hass.io/Docker/pip/etc.): Hass.io

ESP (ESP32/ESP8266, Board/Sonoff): ESP8266

Wemos d1 mini **Affected component: time** https://esphome.io/components/time.html **Description of problem:** First: excuse my bad english. I hope you will unterstand my discription. I have a simple test configuration of my wemos d1 mini, because i have problems with the on_time function in the time component. Sometimes "on_time" works without problems and then suddenly it stopps working, that means, no more execution of actions. in the log of the ESP is no information about an problem,, all other thinks are logged normaly. I use sntp and the time is syncronised, you can see it in the log. During the daytime it works in most cases normal, but without changes in den configuration it sometims stops working. it seams this will happen almost in the evening and it is not possible to get it working during the evneing/night when i upload a new configuration. I have this problem testet on 3 different D1 minis. The Testcode should turn on/off the onboard LED every 5 seconds. **Problem-relevant YAML-configuration entries:** ```yaml time: - platform: sntp id: sntp_time servers: - fritz.box - 128.130.2.3 - time.tugraz.at on_time: - seconds: /5 then: - switch.toggle: onboardLED switch: - platform: gpio name: "ESP CO Onboard LED" id: onboardLED pin: number: D4 inverted: True mode: OUTPUT restore_mode: ALWAYS_OFF on_turn_on: - logger.log: "Schalter On!" on_turn_off: - logger.log: "Schalter Off!" ``` **Logs (if applicable):**
[logger:116]: Log initialized
[23:52:47][C][ota:364]: There have been 0 suspected unsuccessful boot attempts.
[23:52:47][I][app:028]: Running through setup()...
[23:52:47][C][switch.gpio:011]: Setting up GPIO Switch 'ESP CO Onboard LED'...
[23:52:47][D][switch:025]: 'ESP CO Onboard LED' Turning OFF.
[23:52:47][D][switch:045]: 'ESP CO Onboard LED': Sending state OFF
[23:52:47][D][main:288]: Schalter Off!
[23:52:47][D][switch:025]: 'ESP CO Onboard LED' Turning OFF.
[23:52:47][C][wifi:029]: Setting up WiFi...
[23:52:47][D][wifi:272]: Starting scan...
[23:52:47][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '1970-01-01 08:00:00'
[23:52:53][D][wifi:287]: Found networks:
[23:52:53][I][wifi:322]: - 'NETGEAR-3G' [redacted]▂▄▆█
[23:52:53][D][wifi:323]:     Channel: 11
[23:52:53][D][wifi:324]:     RSSI: -52 dB
[23:52:53][D][wifi:326]: - [redacted] [redacted]▂▄▆█
[23:52:53][D][wifi:326]: - [redacted] [redacted]▂▄▆█
[23:52:53][I][wifi:164]: WiFi Connecting to '******'...
[23:52:54][I][wifi:380]: WiFi connected!
[23:52:54][C][wifi:254]:   SSID: [redacted]
[23:52:54][C][wifi:255]:   IP Address: 192.168.188.200
[23:52:54][C][wifi:257]:   BSSID: [redacted]
[23:52:54][C][wifi:258]:   Hostname: 'esp_co'
[23:52:54][C][wifi:262]:   Signal strength: -50 dB ▂▄▆█
[23:52:54][C][wifi:263]:   Channel: 11
[23:52:54][C][wifi:264]:   Subnet: 255.255.255.0
[23:52:54][C][wifi:265]:   Gateway: 192.168.188.1
[23:52:54][C][wifi:266]:   DNS1: 192.168.188.1
[23:52:54][C][wifi:267]:   DNS2: 0.0.0.0
[23:52:54][C][ota:029]: Over-The-Air Updates:
[23:52:54][C][ota:030]:   Address: esp_co.local:8266
[23:52:54][C][ota:032]:   Using Password.
[23:52:54][C][api:030]: Setting up Home Assistant API server...
[23:52:54][C][mqtt:025]: Setting up MQTT...
[23:52:54][I][mqtt:162]: Connecting to MQTT...
[23:52:55][D][switch:029]: 'ESP CO Onboard LED' Toggling ON.
[23:52:55][D][switch:045]: 'ESP CO Onboard LED': Sending state ON
[23:52:55][D][main:269]: Schalter On!
[23:52:56][I][mqtt:202]: MQTT Connected!
[23:52:56][C][sntp:017]: Setting up SNTP...
[23:52:56][I][app:060]: setup() finished successfully!
[23:52:56][D][sntp:059]: Synchronized time: Sat Aug 10 07:52:56 2019
[23:52:56][I][app:096]: esphome version 1.13.6 compiled on Aug  9 2019, 23:34:16
[23:52:56][C][wifi:372]: WiFi:
[23:52:56][C][wifi:254]:   SSID: [redacted]
[23:52:56][C][wifi:255]:   IP Address: 192.168.188.200
[23:52:56][C][wifi:257]:   BSSID: [redacted]
[23:52:56][C][wifi:258]:   Hostname: 'esp_co'
[23:52:56][C][wifi:262]:   Signal strength: -53 dB ▂▄▆█
[23:52:56][C][wifi:263]:   Channel: 11
[23:52:56][C][wifi:264]:   Subnet: 255.255.255.0
[23:52:56][C][wifi:265]:   Gateway: 192.168.188.1
[23:52:56][C][wifi:266]:   DNS1: 192.168.188.1
[23:52:56][C][wifi:267]:   DNS2: 0.0.0.0
[23:52:56][C][switch.gpio:042]: GPIO Switch 'ESP CO Onboard LED'
[23:52:56][C][switch.gpio:043]:   Pin: GPIO2 (Mode: OUTPUT, INVERTED)
[23:52:56][C][switch.gpio:059]:   Restore Mode: Always OFF
[23:52:56][C][template.text_sensor:020]: Template Sensor 'ESP CO Systemzeit'
[23:52:56][C][logger:137]: Logger:
[23:52:56][C][logger:138]:   Level: DEBUG
[23:52:56][C][logger:139]:   Log Baud Rate: 115200
[23:52:56][C][logger:140]:   Hardware UART: UART0
[23:52:56][C][ota:029]: Over-The-Air Updates:
[23:52:56][C][ota:030]:   Address: esp_co.local:8266
[23:52:56][C][ota:032]:   Using Password.
[23:52:56][C][api:103]: API Server:
[23:52:56][C][api:104]:   Address: esp_co.local:6053
[23:52:56][C][mqtt:051]: MQTT:
[23:52:56][C][mqtt:053]:   Server Address: 192.168.188.30:1883 (192.168.188.30)
[23:52:56][C][mqtt:054]:   Username: [redacted]
[23:52:56][C][mqtt:055]:   Client ID: [redacted]
[23:52:56][C][mqtt:057]:   Discovery prefix: 'homeassistant'
[23:52:56][C][mqtt:058]:   Discovery retain: YES
[23:52:56][C][mqtt:060]:   Topic Prefix: 'esp_co'
[23:52:56][C][mqtt:062]:   Log Topic: 'esp_co/debug'
[23:52:56][C][mqtt:065]:   Availability: 'esp_co/status'
[23:52:57][C][sntp:043]: SNTP Time:
[23:52:57][C][sntp:044]:   Server 1: 'fritz.box'
[23:52:57][C][sntp:045]:   Server 2: '128.130.2.3'
[23:52:57][C][sntp:046]:   Server 3: 'time.tugraz.at'
[23:52:57][C][sntp:047]:   Timezone: 'CET-1CEST-2,M3.5.0/2,M10.4.0/3'
[23:52:57][C][mqtt.text_sensor:028]: MQTT Text Sensor 'ESP CO Systemzeit':
[23:52:57][C][mqtt.text_sensor:029]:   State Topic: 'esp_co/sensor/esp_co_systemzeit/state'
[23:52:57][C][mqtt.switch:038]: MQTT Switch 'ESP CO Onboard LED': 
[23:52:57][C][mqtt.switch:039]:   State Topic: 'esp_co/switch/esp_co_onboard_led/state'
[23:52:57][C][mqtt.switch:039]:   Command Topic: 'esp_co/switch/esp_co_onboard_led/command'
[23:53:10][D][api:573]: Client 'Home Assistant 0.96.5 (192.168.188.30)' connected successfully!
[23:53:33][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-09 23:53:32'
[23:54:33][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-09 23:54:32'
[23:54:47][I][ota:046]: Boot seems successful, resetting boot loop counter.
[23:55:33][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-09 23:55:32'

Additional information and things you've tried:

Airfranse commented 5 years ago

I tried it with homassistant time with the result: 1x off, 1x on and then no further actions:

[00:08:26][C][mqtt.switch:039]:` Command Topic: 'esp_co/switch/esp_co_onboard_led/command' [00:08:30][D][switch:029]: 'ESP CO Onboard LED' Toggling OFF. [00:08:30][D][switch:045]: 'ESP CO Onboard LED': Sending state OFF [00:08:30][D][main:282]: Schalter Off! [00:08:35][D][switch:029]: 'ESP CO Onboard LED' Toggling ON. [00:08:35][D][switch:045]: 'ESP CO Onboard LED': Sending state ON [00:08:35][D][main:263]: Schalter On! [00:08:36][D][api:573]: Client 'Home Assistant 0.96.5 (192.168.188.30)' connected successfully! [00:08:36][D][time:030]: Synchronized time: Sat Aug 10 00:08:36 2019 [00:08:54][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-10 00:08:54' [00:09:54][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-10 00:09:54' [00:10:16][I][ota:046]: Boot seems successful, resetting boot loop counter. [00:10:54][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-10 00:10:54' [00:11:54][D][text_sensor:015]: 'ESP CO Systemzeit': Sending state '2019-08-10 00:11:54'

jumblies commented 5 years ago

I get a similar behavior. My on_time is not respected at all on the device.

time:
  - platform: sntp
    id: sntp_time
    timezone: 'America/New_York'
    on_time:
    - seconds: 0 
      minutes: 5
      hours: 19
      then: 
        - light.turn_on: 
            id: h801_2_rgb
Airfranse commented 5 years ago

Tonight at 4:56 my ESP8266 suddenly decided to turn on/off the onboardLED every 5 seconds. So it seams like a bug in the on_time function, because the time is correct from the start.

4:57 ESP CO Onboard LED turned on 4:57 ESP CO Onboard LED turned off 4:57 ESP CO Onboard LED turned on 4:56 ESP CO Onboard LED turned off 4:56 ESP CO Onboard LED turned on 4:44 ESP CO Systemzeit changed to 2019-08-11 04:44:20 4:29 ESP CO Systemzeit changed to 2019-08-11 04:29:20 4:14 ESP CO Systemzeit changed to 2019-08-11 04:14:20 3:59 ESP CO Systemzeit changed to 2019-08-11 03:59:21

jumblies commented 5 years ago

I found that removing sntp and adding HA as time source, my on_time works perfectly. Might be worth a shot if you're still struggling

OttoWinter commented 5 years ago

Ah yes I remember there were some issues with the GPS time code and forgot to push the PR. (I think it was an erronous return type that for some reason wasn't caught by clang-tidy).

EDIT: whoops, commented on wrong issue.

Airfranse commented 5 years ago

i tried also homeassistant time with the same behavior

OttoWinter commented 5 years ago

@Airfranse

  1. Make sure the NTP server supports SNTP protocol and no firewall is in between.
  2. When using homeassistant time source, is home assistant connected to the ESP? With what are they connected, MQTT or native API?
Airfranse commented 5 years ago

for the connection i use the api. the esp gets the time, thats not the Problem. i see the time in HA and it gets it within the first 1-2 minutes after restart of the esp. but the action starts not

Hsxsky commented 4 years ago

I had similar problem. I set up "manual_ip", and forget to add DNS servers.

I think on this IP there is no dns server [23:52:54][C][wifi:266]: DNS1: 192.168.188.1 [23:52:54][C][wifi:267]: DNS2: 0.0.0.0

@Airfranse

llaull commented 4 years ago

i can't use diffente timezome `time:

i have still Asia/Manila time ` - id: page1 lambda: |- it.strftime(0, 0, id(my_font), "%Y-%m-%d %H:%M", id(sntp_time_fr).now());

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

brambo123 commented 3 years ago

I checked out some things and found the likely cause. In some cases, the time may jump back several hours because the code for time zones is not optimal. The on_time automation code remembers when it was last checked whether something needs to be executed. There is already a solution programmed in if he has missed steps because the processor has been too busy. But there is no checking whether the last check is done in the future. In my case, the time jumps back 8 hours (because the sntp code has gmt+8 by default, who came up with that?), no check is performed for just as long. After 8 hours, the cron tasks start working.