Timer component, timer stops before time is up

I have been trying to setup three timers using the timer component but each time I use them they do not reach their full time and reset back to idle before the initial set time is up.

Each timer has an initial time set of 10 hours, yesterday one timer reset to idle after 7h50, the other two timers reset to idle after 2h10, but they all reset around the same time of day (within a couple of minutes of each other)

This morning I started one of the timers and this time it only managed 45 minutes of 10 hours before it reset back to idle

There are no error in the log, so I am but stuck at how to troubleshoot.

Anyone know what could be going on or have something similar happen?

Can you share your code?
Also it sounds like you have something that either resets the timers in a different automation, or potentially have your HA restart?

Also, you might want to look in home-assistant.log at the time when the timers change to idle (look for a state_changed event for the timer.) Is there anything in the log right before that that would explain why it changed to idle? E.g., any service call to the timer domain?

Here is the timer config:

timer:
  pig_heater_back:
    name: Pig Heater Back
    duration: '10:00:00'
  pig_heater_front:
    name: Pig Heater Front
    duration: '10:00:00'
  pig_heater_spare:
    name: Pig Heater Spare
    duration: '10:00:00'

Here is the switch config. I use these switches to activate the timers:

switch:
  - platform: template
    switches:
      pig_heater_back:
        friendly_name: Pig Heater Back
        value_template: "{{ is_state('timer.pig_heater_back', 'active') }}"
        turn_on:
          service: timer.start
          data:
            entity_id: timer.pig_heater_back
        turn_off:
          service: timer.finish
          data:
            entity_id: timer.pig_heater_back
      pig_heater_front:
        friendly_name: Pig Heater Front
        value_template: "{{ is_state('timer.pig_heater_front', 'active') }}"
        turn_on:
          service: timer.start
          data:
            entity_id: timer.pig_heater_front
        turn_off:
          service: timer.finish
          data:
            entity_id: timer.pig_heater_front
      pig_heater_spare:
        friendly_name: Pig Heater Spare
        value_template: "{{ is_state('timer.pig_heater_spare', 'active') }}"
        turn_on:
          service: timer.start
          data:
            entity_id: timer.pig_heater_spare
        turn_off:
          service: timer.finish
          data:
            entity_id: timer.pig_heater_spare

There are no automations linked to either the timers or the switches.
the log file is nice and clean with no entries and HA has not restarted since adding the above code
I also looked in the Logbook, and there is nothing I can see round the time of the early finish that would explain (to me at least) the early timer finish

This is the logbook for when they all went to idle early overnight
image

and the one from this morning
image

The only thing close to the time both times is the Thermostat Status change (which is not really a status change, for some reason it is reporting Online every time it reports status)

Any clues there?

Need to look at the home-assistant.log, not Logbook. Go to your config folder and find home-assistant.log and look there.

Hi @petro

home-assistant.log is empty. there have been no errors or other entries added to the log file during this boot of HA

You’ll need to change your logger to info to see everything, maybe even debug.

logger:
  default: info
  logs:
    homeassistant.components.timer: debug

ah ok, thanks @petro, I will add that now

Your switches themselves stop the timers. The log clearly shows the switch being turned off, and immediately the corresponding timer goes to idle. Given your configuration, that is to be expected.

EDIT: On the other hand, I see the switches’ states are determined by the state of the corresponding timer. So it could be the other way round - the timer went idle, which caused the switch to turn off.

You definitely need to look in the log to see the sequence of events. I would turn the default to DEBUG for everything, at least while you’re trying to see what the cause is.

ok I am open to that theory, but what could be turning the switches off?
No one was awake when it happened last night, so human interaction can be ruled out for last nights. this morning I did not turn the switch off, but I cant say for sure that no one else didn’t.

I have turned on the debug in the log, will see what gets added there :slight_smile:

1 Like

They all just reset back to idle again all at the same time:
image

The Front and Back I think could have reached their natural end of time, but the Spare still had at least 7 hours left on the timer when it reset back to idle

There is nothing in the log, even though the extra debugging logging.

Any ideas where to look next?

I suspect you don’t have logger set correctly, or you’re not interpreting home-assistant.log correctly. When a timer is stopped (and you have debug enabled) there will be a line like this in home-assistant.log:

2019-02-02 12:20:49 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=timer, service_data=entity_id=['timer.xxx'], service=finish>

The service= part might be cancel instead of finish.

Then if you look above that in home-assistant.log, there should be a clue as to what called that service.

I’d recommend changing your logger config to:

logger:
  default: debug

Just that, and nothing else. (I.e., debug enabled for everything.)

I suppose there could be some kind of bug, but I really think there should be some clues in the log.

thanks @pnbruckner, I will set the logger config as you have detailed so as to catch everything, at the moment I have it set exactly as petro has in his post, but maybe there is something else outside of the timer component at work here?

There is no text at all in the log file (other than an info message saying I am using a sensor custom component added at startup), I guess that will change a lot when I restart with the debug for all :slight_smile:

Actually, homeassistant.components.timer is not a valid component namespace. So effectively you had the log level set to info for everything.

Exactly. Seeing the timer changing state in the log is only a way of localizing where you should look for the root cause.

understood.

HA restarted, started a timer and I see a fair few timer events in the log, one of which:

2019-02-02 20:37:21 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event timer.started[L]: entity_id=timer.pig_heater_spare>

So now to wait and see if it / they finish early again

Thanks for your help with this

1 Like

This may not help with your issue but I don’t think you need “data” in your switches code…

    turn_on:
      service: timer.start
      entity_id: timer.pig_heater_back

The data part would be for passing a different duration than the default…

    turn_on:
      service: timer.start
      entity_id: timer.pig_heater_back
      data:
        duration: '00:02:00'

Edit: actually this probably will help because I think your code in its current form is starting all timers when you turn any one timer on, and finishing all timers when any one timer ends.

hi @jimbob1001

I can try that way of setting up the code, but at the moment the correct timer does start and stop when the relevant switch is manually turned on and off. The only issue I have is with the timers ending prematurely by themselves, although they have been behaving themselves since adding the debug level logging :confused:

I like the look of that updated code, and was wondering, could the duration be taken from an input_number so I could start the timers with a duration chosen from the GUI?

Yes I believe so something like this maybe (I have never tried this so don’t actually know)…

turn_on:
  service: timer.start
  entity_id: timer.pig_heater_back
  data_template:
    duration: >
      {{ states('input_number.heater_duration') }}
1 Like

thanks, I will give it a go

It’s strange, the timers have been good as gold since adding the debugging. I might take debugging off and see what happens