Latest HA release 0.81 causing excessive time spent in utility loop

Hi,

Ever since I upgraded to HA 0.81 release, I am noticing more of these events. In some instances, some modules (automations) did not run because of these events.

How do I find out which module/sensor causing this?

2018-10-30 11:44:38.810455 WARNING AppDaemon: Excessive time spent in utility loop: 1373.0ms
2018-10-30 11:44:43.251619 WARNING AppDaemon: Excessive time spent in utility loop: 1431.0ms
2018-10-30 11:44:47.584751 WARNING AppDaemon: Excessive time spent in utility loop: 1325.0ms
2018-10-30 11:44:50.826284 WARNING AppDaemon: Excessive time spent in utility loop: 1236.0ms
2018-10-30 11:44:55.742170 WARNING AppDaemon: Excessive time spent in utility loop: 901.0ms

I have added ‘utility_delay’ and ‘utility_skew’ entries but these events were occurring almost every day.

appdaemon.yaml

log:
  logfile: /conf/logs/appdaemon.log
  errorfile: /conf/logs/appdaemonerr.log
  logsize: 100000
  log_generations: 3
  utility_delay: 5
  utility_skew: 4
  production_mode: true
appdaemon:
  threads: 10
  plugins:
    HASS:
      type: hass
      ha_url: http://192.168.86.226:8123
      ha_key: xxxxx

excessive time warnings can not cause that automations dont run.

normally the utility loop takes up to 1 second to run
if the loop takes longer it is mentioned with this warning, but it only has effect on the speed that AD is running.

i myself did notice a long time ago that things like this can occur when the device that runs HA and AD isnt restarted but HA and AD are restarted several times.

so please restart the device and see if the problems dissapear.

and where did you read that you can set utility_delay and skew?
the only available option is max_ultility_skew which makes the warning dissapear, not the problem.

max_utility_skew and production_mode should be in the appdaemon section, not in the log section where they do nothing.

if it is HA that is just way slower and causing the trouble it can very well be that your troubles go away when you place the settings at the right place.

but i think its also time to start thinking if you can have better time management inside your apps.
see if there are things that hold up your apps. avoid things like sleep, with the use of requests set right timeouts, etc.
make sure that every app that you got running is 1 straight line from start to end and as fast as possible.

As usual, Rene covers the subject very thoroughly - thanks :slight_smile: Only one small addition - utility_delay does exist in the code but is undocumented because when people start getting these problems, changing this and max_utility_delay usually only mask the real issue.

Also, if you have production mode set there is no point in messing with the other 2 as they will be ignored.

1 Like

I thought when I add these entries there wouldn’t any entries in the log file but these excessive time spent still showing up.

I was trying out different settings and was not sure how that flag works.

There were no issues prior to HA 0.80 release. Also, it could be some issues related to my Wink hub. I added following whenever any light/switch turns on or off.

      if "speed" in self.args:
          if int(new) > self.args["speed"]:
              msg = self.friendly_name(entity) + " is {}".format(new)
              self.set_state("sensor.appd_notify_message", state=msg)
      else:
            self.log(self.friendly_name(entity) + " turned " + new + " - Refreh states from Wink hub")
          device, entity_name = self.split_entity(entity)
          if (device == "light" or device == "switch"):
              self.call_service('wink/refresh_state_from_wink')

But there are no entries in HA log if that call was made or not.

Thank you, Rene. I thought these warnings would somehow interfere with appdaemon. As I explained in my other response, it could be my Wink hub not responding correctly to sensor states. It’s frustrating especially when the lights supposed to turn on/off when the motion was detected.

My bad. I corrected this.

log:
  #logfile: STDOUT
  #errorfile: STDERR
  # /conf is /mnt/user/appdata/appdaemon
  #accessfile: /conf/logs/appdaemonaccess.log
  logfile: /conf/logs/appdaemon.log
  errorfile: /conf/logs/appdaemonerr.log
  logsize: 100000
  log_generations: 3
  # utility_delay: 5
  # utility_skew: 4
  # production_mode: true
appdaemon:
  production_mode: true
  threads: 10
  plugins:
    HASS:
      type: hass
      ha_url: http://192.168.86.226:8123
      ha_key: xxxxxx

remember that when you set to production mode changes to apps or apps.yaml will not be noticed untill you restart appdaemon!
but it will speed up appdaemon quite a bit.

if normally the lights do turn on and off and you didnt change anything in your code and that stops working there is a problem that makes that AD doesnt get the motion detection or HA doesnt understand your service or HA cant perform the action.

to make sure that AD does what it needs to do add a logentry at the beginning and the end from your callback. then you know that it isnt AD and you know what other parts to look at.