Wemo switch turns off then on when timer finishes

oldchap · March 7, 2023, 10:16am

I have an automation and timer set up to turn off a Wemo switch once it’s been on for a fixed period of time. (it’s running a kids electric blanket - to prevent it being left on overnight) When the timer runs out, the turn_off action is called; this turns the wemo off but then it immediately turns back on again. Otherwise HA controls the wemo perfectly; I can turn it off and on through the dashboard with no trouble.

The automation for turning off looks like this:

alias: N and M blanket off
description: ""
trigger:
  - platform: time
    at: "23:00:00"
  - platform: event
    event_type: timer.finished
    event_data:
      entity_id: timer.n_and_m_blanket_off
condition: []
action:
  - type: turn_off
    device_id: 223dce31f01c42c551926a5309a74a88
    entity_id: switch.n_and_m_blanket
    domain: switch
mode: single

(the only slight complication being that there’s a failsafe trigger to always turn it off at 23:00:00)

and the automation to start the timer looks like this:

alias: N and M blanket restart timer
description: ""
trigger:
  - platform: device
    type: turned_on
    device_id: 223dce31f01c42c551926a5309a74a88
    entity_id: switch.n_and_m_blanket
    domain: switch
condition: []
action:
  - service: timer.start
    data:
      duration: "7200"
    target:
      entity_id: timer.n_and_m_blanket_off
mode: single

There is another automation to cancel the timer in case the switch is turned off manually:

alias: N and M blanket cancel timer
description: ""
trigger:
  - platform: device
    type: turned_off
    device_id: 223dce31f01c42c551926a5309a74a88
    entity_id: switch.n_and_m_blanket
    domain: switch
condition: []
action:
  - service: timer.cancel
    data: {}
    target:
      entity_id: timer.n_and_m_blanket_off
mode: single

and finally another one kicks the whole thing off at the same time:

alias: N and M blanket
description: ""
trigger:
  - platform: time
    at: "19:35"
condition:
  - condition: state
    entity_id: input_boolean.blankets_enabled
    state: "on"
action:
  - type: turn_on
    device_id: 223dce31f01c42c551926a5309a74a88
    entity_id: switch.n_and_m_blanket
    domain: switch
mode: single

The logbook from yesterday looks like this:

N and M blanket turned off triggered by service switch.turn_off
21:35:04 - 13 hours ago - Sandy Brownlee
N and M blanket turned on triggered by automation N and M blanket off triggered by event 'timer.finished'
21:35:00 - 13 hours ago
N and M blanket turned off triggered by automation N and M blanket off triggered by event 'timer.finished'
21:35:00 - 13 hours ago
N and M blanket turned on triggered by automation N and M blanket triggered by time
19:35:00 - 15 hours ago

(you can see me turning the switch off manually after it turned itself back on).

The trace for the “turning off” shows the turn off/on happening:

…which leads me to believe there’s something weird on the HA rather than a fault with the Wemo itself. Is there anything wrong with the way I’ve configured things? Or a known bug with switches that causes this? I’ve looked for other examples of this happening but can’t find any.

I’m running Home Assistant Core 2022.12.1 on Raspbian 10, on a Raspberry Pi 4B.

Thanks!

oldchap · March 23, 2023, 3:33pm

I will post a further update if I properly get to the bottom of this…

I deleted everything and tried again, but still the problem persisted.

Then I found that simply changing the duration in “alias: N and M blanket restart timer” to 1:55:0 seems to have cured the problem. The switch now goes off and stays off when the timer finishes. Possibly something else is happening at the magic two hour mark but I don’t know what!

tom_l · March 23, 2023, 4:49pm

Looks like bad communication with the switch. If you tell it to turn off the state immediately changes to off but will toggle back to on if the command failed. Check Settings → logs.

oldchap · March 28, 2023, 8:15am

Thanks. I will see if I can replicate it to check the logs - if there was anything from the error it’s dropped off the end of the log now.

The strange thing is that it’s not happened again since changing the duration of the timer - but was quite consistent before I did so.

tom_l · March 28, 2023, 8:17am

The system log does not “drop off” anything. Even after a restart there is a copy of it available.

oldchap · March 28, 2023, 8:33am

Interesting. All I can see in the HA directory is:
-rw-r–r-- 1 homeassistant homeassistant 23714 Mar 28 09:15 home-assistant.log
-rw-r–r-- 1 homeassistant homeassistant 1322 Mar 22 09:44 home-assistant.log.1
…nothing older (I did two reboots that day so the small one contains nothing helpful)

I don’t see anything relevant in /var/log. Should I be looking somewhere else?

tom_l · March 28, 2023, 9:17am

Then it is gone. Each reboot home-assistant.log is copied to home-assistant.log.1

oldchap · March 28, 2023, 1:00pm

Okay, thanks. In that case I will try to replicate the issue and report anything that I can see in the log.

oldchap · March 31, 2023, 10:52am

A couple more updates…

I replicated the error by setting the timer to 2 hours again. Nothing (errors or otherwise) appears in the log for a few hours either side of when the switch should have turned off. Again the switch appears to have been turned off, then immediately on, by the automation:

However, I have also tried setting the default duration for the timer helper to 0; with the duration in the action for the “N and M blanket restart timer” automation set at 2 hours. This fixes the problem. It seems to me that having the duration in the timer helper and the duration given in the call to timer.start being the same is the cause of the trouble. I’m trying it a few times to confirm but this does seem to be consistent.

Is there a way to enable more detailed logging somewhere to see what the underlying cause might be?