Announcement - AppDaemon 3.0!

Rene has it right - dashboard was designed to have a 100% controllable and deterministic layout - I’m not planning to change that.

2 Likes

Reporting back. Turned the dashboard off and things seemed Ok for most of the day. My sunset automation didn’t fire still though and then when i checked in later in the evening, none of the other automation would work either ( i have some switch triggered ones).
There was nothing in the err.log, however this appeared in the info.log. I didn’t restart AD manaully so it must have re-started itself

018-03-24 21:42:39.255416 WARNING AppDaemon: Excessive time spent in utility loop: 1181.0ms
2018-03-24 21:52:42.091241 WARNING AppDaemon: Excessive time spent in utility loop: 2586.0ms
2018-03-24 21:55:49.877726 INFO AppDaemon Version 3.0.0 starting
2018-03-24 21:55:49.879129 INFO Configuration read from: /config/appdaemon/appdaemon.yaml
2018-03-24 21:55:49.882993 INFO AppDaemon: Starting Apps
2018-03-24 21:55:49.896087 INFO AppDaemon: Loading Plugin HASS using class HassPlugin from module hassplugin
2018-03-24 21:55:50.013581 INFO AppDaemon: HASS: HASS Plugin Initializing
2018-03-24 21:55:50.026360 INFO AppDaemon: HASS: HASS Plugin initialization complete
2018-03-24 21:55:50.029102 INFO Dashboards are disabled
2018-03-24 21:55:50.030255 INFO Starting API
2018-03-24 21:55:50.040539 WARNING AppDaemon: ------------------------------------------------------------
2018-03-24 21:55:50.041669 WARNING AppDaemon: Unexpected error in api thread
2018-03-24 21:55:50.042519 WARNING AppDaemon: ------------------------------------------------------------
2018-03-24 21:55:50.062710 WARNING AppDaemon: Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/appdaemon/adapi.py", line 43, in __init__
    f = loop.create_server(handler, "0.0.0.0", int(self.api_port), ssl=context)
TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType'

2018-03-24 21:55:50.063844 WARNING AppDaemon: ------------------------------------------------------------
2018-03-24 21:55:51.431857 INFO AppDaemon: HASS: Connected to Home Assistant 0.65.6
2018-03-24 21:55:52.605816 INFO AppDaemon: Got initial state from namespace default
2018-03-24 21:55:54.021153 INFO AppDaemon: Reading config
2018-03-24 21:55:54.851033 INFO AppDaemon: /config/appdaemon/apps/apps.yaml added or modified
2018-03-24 21:55:54.852354 INFO AppDaemon: /config/appdaemon/apps/apps.yaml added or modified
2018-03-24 21:55:54.853375 INFO AppDaemon: App 'utils' added

I also appear to get a lot of excessive time in loop log entries, but this one also indicated that something stopped working

2018-03-24 22:56:01.550234 WARNING AppDaemon: Excessive time spent in utility loop: 1459.0ms
2018-03-24 23:06:03.071193 WARNING AppDaemon: Excessive time spent in utility loop: 1271.0ms
2018-03-24 23:15:32.428718 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:15:37.595367 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:15:42.608271 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:15:47.632226 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:15:52.644892 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:15:57.656204 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:02.938603 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:07.950312 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:12.961340 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:17.972722 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:22.984255 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:27.998127 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:33.016530 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:38.309831 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:43.322003 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:48.333508 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:53.345864 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:16:58.368098 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:03.387400 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:08.404502 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:13.420675 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:18.434262 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:23.451603 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:28.469034 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:33.487165 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:38.774451 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:43.791135 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:48.812666 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:53.826590 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:17:58.837651 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:03.849502 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:08.861339 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:13.873740 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:18.889590 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:23.902255 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:28.914586 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:33.927665 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:39.086107 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:44.098589 WARNING AppDaemon: HASS: Disconnected from Home Assistant, retrying in 5 seconds
2018-03-24 23:18:50.196629 INFO AppDaemon: HASS: Connected to Home Assistant 0.65.6
2018-03-24 23:18:54.833041 INFO AppDaemon: Processing restart for HASS
2018-03-24 23:18:54.839660 INFO AppDaemon: Terminating notify_door_open_closed_front
2018-03-24 23:18:54.841365 INFO AppDaemon: Terminating utils
2018-03-24 23:18:54.842792 INFO AppDaemon: Terminating auto_turnoff_in_five
2018-03-24 23:18:54.844197 INFO AppDaemon: Terminating auto_turnoff_in_ten
2018-03-24 23:18:54.845612 INFO AppDaemon: Terminating auto_turrn_off_time
2018-03-24 23:18:54.847100 INFO AppDaemon: Terminating auto_turnoff_front_garden
2018-03-24 23:18:54.848609 INFO AppDaemon: Terminating auto_turn_on_off_backyard_lights
2018-03-24 23:18:54.849964 INFO AppDaemon: Terminating auto_turnoff_motion_upstairs_gallery
2018-03-24 23:18:54.851297 INFO AppDaemon: Terminating auto_turnon_off_motion_front_porch
2018-03-24 23:18:54.852698 INFO AppDaemon: Terminating auto_turnoff_motion_light_study
2018-03-24 23:18:54.854591 INFO AppDaemon: Terminating auto_turn_on_off_presence_scott
2018-03-24 23:18:54.855943 INFO AppDaemon: Terminating auto_turn_on_off_presence_lia
2018-03-24 23:18:54.857963 INFO AppDaemon: Terminating auto_turn_on_off_presence_emily
2018-03-24 23:18:54.859309 INFO AppDaemon: Terminating auto_turn_on_off_presence_laura
2018-03-24 23:18:54.860652 INFO AppDaemon: Terminating auto_turn_on_off_presence_zara
2018-03-24 23:18:54.861943 INFO AppDaemon: Terminating auto_turn_on_off_front_garden_lights
2018-03-24 23:18:54.863293 INFO AppDaemon: Terminating auto_turn_on_off_sunset_test
2018-03-24 23:18:54.864577 INFO AppDaemon: Terminating study_motion_scene
2018-03-24 23:18:54.865904 INFO AppDaemon: Terminating front_sprinkler_state_change
2018-03-24 23:18:54.867398 INFO AppDaemon: Terminating back_sprinkler_state_change
2018-03-24 23:18:54.869075 INFO AppDaemon: Terminating notify_door_open_closed_garage
2018-03-24 23:18:54.874615 INFO AppDaemon: Initializing app auto_turnoff_in_five using class AutoTurnOffLightsDelay from module auto_turn_off_delay
2018-03-24 23:18:54.879074 INFO AppDaemon: Initializing app auto_turnoff_in_ten using class AutoTurnOffLightsDelay from module auto_turn_off_delay
2018-03-24 23:18:54.882695 INFO AppDaemon: Initializing app auto_turrn_off_time using class AutoTurnOffLightsTime from module auto_turn_off_time
2018-03-24 23:18:54.889690 INFO AppDaemon: Initializing app auto_turnoff_front_garden using class AutoTurnOffLightsDelay from module auto_turn_off_delay
2018-03-24 23:18:54.892616 INFO AppDaemon: Initializing app auto_turn_on_off_backyard_lights using class AutoTurnOnOffLights from module auto_turn_on_off
2018-03-24 23:18:54.895458 INFO AppDaemon: Initializing app auto_turnoff_motion_upstairs_gallery using class AutoTurnOnOffLightsMotion from module auto_turn_on_off_motion
2018-03-24 23:18:54.897970 INFO AppDaemon: Initializing app auto_turnon_off_motion_front_porch using class AutoTurnOnOffLightsMotion from module auto_turn_on_off_motion
2018-03-24 23:18:54.900241 INFO AppDaemon: Initializing app auto_turnoff_motion_light_study using class AutoTurnOnOffLightsMotionLumens from module auto_turn_on_off_motion_lumen

my err.log is completely empty though which is strange.

I am running Hassio 0.65.6 and this seems to have been problematic release with 6 hotfixes so far, so not sure if that is causing issues. I do also see some entries in my hassio.log indicated that hassio has lost connection with wemo devices that I have intermittently- I believe there are some issue with wemo.py library. If AD is running a app that is trying to access an entity that has intermittently been disabling in hassio would that report an error in the log?

here is a sample of the hassio.log

OSError: [Errno 9] Bad file descriptor
2018-03-25 07:13:31 WARNING (MainThread) [homeassistant.components.switch.wemo] Lost connection to Spare Bedroom Light
2018-03-25 07:13:36 WARNING (SyncWorker_11) [pywemo.ouimeaux_device.api.service] Error communicating with Spare Bedroom Light, retry 0
2018-03-25 07:13:37 WARNING (MainThread) [homeassistant.components.switch.wemo] Lost connection to Downstairs Bathroom Light
2018-03-25 07:13:37 WARNING (MainThread) [homeassistant.components.switch] Updating wemo switch took longer than the scheduled update interval 0:00:10
2018-03-25 07:13:42 WARNING (SyncWorker_3) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light, retry 0
2018-03-25 07:13:46 ERROR (SyncWorker_11) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.202
2018-03-25 07:13:52 ERROR (SyncWorker_3) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.173
2018-03-25 07:15:11 ERROR (SyncWorker_11) [pywemo.ouimeaux_device] Unable to reconnect with Spare Bedroom Light in 5 tries. Stopping.
2018-03-25 07:15:16 ERROR (SyncWorker_3) [pywemo.ouimeaux_device] Unable to reconnect with Downstairs Bathroom Light in 5 tries. Stopping.
2018-03-25 07:15:21 WARNING (SyncWorker_11) [pywemo.ouimeaux_device.api.service] Error communicating with Spare Bedroom Light, retry 1
2018-03-25 07:15:21 WARNING (MainThread) [homeassistant.components.switch.wemo] Lost connection to Garage Light
2018-03-25 07:15:26 WARNING (SyncWorker_3) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light, retry 1


2018-03-25 07:29:03 WARNING (Wemo Events Thread) [pywemo.subscribe] Resubscribe error for <WeMo LightSwitch "Downstairs Bathroom Light"> (HTTPConnectionPool(host='192.168.0.173', port=49154): Max retries exceeded with url: /upnp/event/basicevent1 (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x6f6598d0>: Failed to establish a new connection: [Errno 113] Host is unreachable',))), will retry in 60s
2018-03-25 07:29:08 WARNING (SyncWorker_5) [pywemo.ouimeaux_device.api.service] Error communicating with Spare Bedroom Light, retry 0
2018-03-25 07:29:10 WARNING (MainThread) [homeassistant.components.switch.wemo] Lost connection to Spare Bedroom Light
2018-03-25 07:29:14 ERROR (SyncWorker_16) [pywemo.ouimeaux_device] Unable to reconnect with Downstairs Bathroom Light in 5 tries. Stopping.
2018-03-25 07:29:14 ERROR (SyncWorker_16) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light. Giving up
2018-03-25 07:29:18 ERROR (Wemo Events Thread) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.173
2018-03-25 07:29:18 WARNING (SyncWorker_7) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light, retry 0
2018-03-25 07:29:21 WARNING (MainThread) [homeassistant.components.switch.wemo] Lost connection to Downstairs Bathroom Light
2018-03-25 07:29:23 ERROR (SyncWorker_5) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.202
2018-03-25 07:29:33 ERROR (SyncWorker_7) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.173
2018-03-25 07:29:36 WARNING (SyncWorker_7) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light, retry 1
2018-03-25 07:29:51 ERROR (SyncWorker_7) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.173
2018-03-25 07:29:51 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8)
2018-03-25 07:29:51 ERROR (Recorder) [homeassistant.components.recorder] Error in database connectivity: (sqlite3.OperationalError) disk I/O error (Background on this error at: http://sqlalche.me/e/e3q8). (retrying in 3 seconds)
2018-03-25 07:29:54 WARNING (SyncWorker_7) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light, retry 2
2018-03-25 07:30:09 ERROR (SyncWorker_7) [pywemo.ouimeaux_device] Unable to re-probe wemo at 192.168.0.173
2018-03-25 07:30:09 ERROR (SyncWorker_7) [pywemo.ouimeaux_device.api.service] Error communicating with Downstairs Bathroom Light. Giving up
2018-03-25 07:30:11 ERROR (Wemo Events Thread) [pywemo.ssdp] Socket error while discovering SSDP devices
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/urllib3/connection.py", line 141, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/util/connection.py", line 83, in create_connection
    raise err
  File "/usr/lib/python3.6/site-packages/urllib3/util/connection.py", line 73, in create_connection
    sock.connect(sa)
OSError: [Errno 113] Host is unreachable

Just checked and my sunset automation didn’t fire again. No error in the error log, but my info.log is filling up fast with the following.This is just a snipet, these continue for atleast 800 lines with the ques size number growning

2018-03-25 19:12:27.732652 WARNING AppDaemon: Queue size is 230, suspect thread starvation
2018-03-25 19:12:28.773436 WARNING AppDaemon: Queue size is 230, suspect thread starvation
2018-03-25 19:12:29.808488 WARNING AppDaemon: Queue size is 230, suspect thread starvation
2018-03-25 19:12:36.275667 WARNING AppDaemon: Excessive time spent in utility loop: 2297.0ms
2018-03-25 19:15:31.267863 WARNING AppDaemon: Queue size is 240, suspect thread starvation
2018-03-25 19:15:32.301872 WARNING AppDaemon: Queue size is 240, suspect thread starvation
2018-03-25 19:15:33.335441 WARNING AppDaemon: Queue size is 240, suspect thread starvation
2018-03-25 19:15:34.369107 WARNING AppDaemon: Queue size is 240, suspect thread starvation
2018-03-25 19:15:35.425597 WARNING AppDaemon: Queue size is 240, suspect thread starvation
2018-03-25 19:15:36.460891 WARNING AppDaemon: Queue size is 240, suspect thread starvation
2018-03-25 19:15:37.502538 WARNING AppDaemon: Queue size is 240, suspect thread starvation

there are also a lot of instance of these message in the log

2018-03-25 19:26:03.690843 INFO AppDaemon: --------------------------------------------------
2018-03-25 19:26:03.691846 INFO AppDaemon: Threads
2018-03-25 19:26:03.692689 INFO AppDaemon: --------------------------------------------------
2018-03-25 19:26:03.693609 INFO AppDaemon: Currently busy threads: 0
2018-03-25 19:26:03.694579 INFO AppDaemon: Most used threads: 2 at 2018-03-25 10:37:08.302074
2018-03-25 19:26:03.695517 INFO AppDaemon: Last activity: 2018-03-25 16:32:42.302074
2018-03-25 19:26:03.696387 INFO AppDaemon: --------------------------------------------------
2018-03-25 19:26:03.698500 INFO AppDaemon: thread-1 - current callback: idle since 2018-03-25 15:00:20.302074, alive: False
2018-03-25 19:26:03.699611 INFO AppDaemon: thread-2 - current callback: idle since 2018-03-25 14:55:12.302074, alive: False
2018-03-25 19:26:03.700607 INFO AppDaemon: thread-3 - current callback: idle since 2018-03-24 23:18:58, alive: False
2018-03-25 19:26:03.701596 INFO AppDaemon: thread-4 - current callback: idle since 2018-03-25 14:28:36.302074, alive: False
2018-03-25 19:26:03.702646 INFO AppDaemon: thread-5 - current callback: idle since 2018-03-25 16:32:42.302074, alive: False
2018-03-25 19:26:03.703612 INFO AppDaemon: thread-6 - current callback: idle since 2018-03-25 12:10:06.302074, alive: False
2018-03-25 19:26:03.704536 INFO AppDaemon: thread-7 - current callback: idle since 2018-03-25 15:22:03.302074, alive: False
2018-03-25 19:26:03.705504 INFO AppDaemon: thread-8 - current callback: idle since 1970-01-01 10:00:00, alive: False
2018-03-25 19:26:03.706536 INFO AppDaemon: thread-9 - current callback: idle since 2018-03-25 13:48:44.302074, alive: False
2018-03-25 19:26:03.707826 INFO AppDaemon: thread-10 - current callback: idle since 1970-01-01 10:00:00, alive: False
2018-03-25 19:26:03.708822 INFO AppDaemon: --------------------------------------------------

I am guessing this is grinding things to a halt and that is why the automation stop working. If I reboot all seems good with the other automations ( i can test sunset ones as TimeTravel doesn’t work on Hassio

appdaemon is losing connection to HA. and then it restarts, but not correctly.
also there seems to be a problem with the api.

please restart everything and show the logs from the start. i got the feeling there is something wrong from the beginning.

Yes, something is killing the worker threads, then when they are all dead everything backs up and you get the Queue warnings. I haven;t seen this before.

So lets take it step by step as Rene suggested.

Thanks with running with this guys, I appreciate the help.

Just some things i noticed.
When I got home I noticed the access log full of the following. I enabled the dashboard last night

2018-03-26 20:37:01.473769 INFO HADashboard: Dashboard disconnected
2018-03-26 20:47:02.739627 INFO HADashboard: New dashboard connected: Kitchen Dashboard

There is still nothing in my err.log ( I think this is a little strange). My info log cotains pages of the suspect thread starvation message.

The Hassio widget for AD, I did notice this inthe log display.

File "/usr/lib/python3.6/asyncio/selector_events.py", line 724, in _read_ready
    data = self._sock.recv(self.max_size)
TimeoutError: [Errno 110] Operation timed out
Fatal read error on socket transport
protocol: <RequestHandler none:none connected>
transport: <_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
  File "/usr/lib/python3.6/asyncio/selector_events.py", line 724, in _read_ready
    data = self._sock.recv(self.max_size)
TimeoutError: [Errno 110] Operation timed out
Fatal read error on socket transport
protocol: <RequestHandler none:none connected>
transport: <_SelectorSocketTransport fd=12 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
  File "/usr/lib/python3.6/asyncio/selector_events.py", line 724, in _read_ready
    data = self._sock.recv(self.max_size)
TimeoutError: [Errno 110] Operation timed out
Fatal read error on socket transport
protocol: <RequestHandler none:none connected>
transport: <_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):

It is repeated several times. not sure why this isn’t going to my err.log

here is my current appdaemon.yaml

secrets: /config/secrets.yaml
log:
  logfile: /config/appdaemon/apps/logs/info.log
  errorfile: /config/appdaemon/apps/logs/err.log
  accessfile: /config/appdaemon/apps/logs/access.log
  logsize: 100000
  log_generations: 4

appdaemon:
  disable_apps: 0
  threads: 10
  api_port: 5000
  api_key: !secret http_password
  api_ssl_certificate: /ssl/fullchain.pem
  api_ssl_key: /ssl/privkey.pem
  log_thread_actions: 0
  plugins:
    HASS:
      type: hass
      ha_url: !secret ha_url
      ha_key: !secret http_password


hadashboard:
  dash_url: http://127.0.0.1:5050
  dash_dir: /config/appdaemon/dashboards

As requested, I restarted AD

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] 00-banner.sh: executing... 
-----------------------------------------------------------
 Hass.io Add-on: AppDaemon3 v1.0.0
 Python Apps and HADashboard using AppDaemon 3.x for Home Assistant
 From: Community Hass.io Add-ons
 By: Franck Nijhof <[email protected]>
-----------------------------------------------------------
[cont-init.d] 00-banner.sh: exited 0.
[cont-init.d] 01-log-level.sh: executing... 
Log level is set to INFO
[cont-init.d] 01-log-level.sh: exited 0.
[cont-init.d] 02-updates.sh: executing... 
INFO: You are running the latest version of this add-on
[cont-init.d] 02-updates.sh: exited 0.
[cont-init.d] 03-version-requirements.sh: executing... 
INFO: Supervisor version requirements checks passed.
[cont-init.d] 03-version-requirements.sh: exited 0.
[cont-init.d] 20-init-configuration.sh: executing... 
[cont-init.d] 20-init-configuration.sh: exited 0.
[cont-init.d] 21-compiled-dir.sh: executing... 
[cont-init.d] 21-compiled-dir.sh: exited 0.
[cont-init.d] 30-auto-password.sh: executing... 
[cont-init.d] 30-auto-password.sh: exited 0.
[cont-init.d] 31-ha-url.sh: executing... 
WARNING: You are using an non-recommended Home Assistant URL!
WARNING: Setting the "ha_url" option in your AppDaemon config to
WARNING: "http://hassio/homeassistant" is recommended!
[cont-init.d] 31-ha-url.sh: exited 0.
[cont-init.d] 50-compiled-symlink.sh: executing... 
[cont-init.d] 50-compiled-symlink.sh: exited 0.
[cont-init.d] 80-system-packages.sh: executing... 
[cont-init.d] 80-system-packages.sh: exited 0.
[cont-init.d] 81-python-packages.sh: executing... 
[cont-init.d] 81-python-packages.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
starting version 3.2.4

The following was added to my info.log after the restart of AD

2018-03-26 21:13:44.508477 INFO AppDaemon Version 3.0.0 starting
2018-03-26 21:13:44.509901 INFO Configuration read from: /config/appdaemon/appdaemon.yaml
2018-03-26 21:13:44.514552 INFO AppDaemon: Starting Apps
2018-03-26 21:13:44.532498 INFO AppDaemon: Loading Plugin HASS using class HassPlugin from module hassplugin
2018-03-26 21:13:44.658561 INFO AppDaemon: HASS: HASS Plugin Initializing
2018-03-26 21:13:44.660670 INFO AppDaemon: HASS: HASS Plugin initialization complete
2018-03-26 21:13:44.662582 INFO Starting Dashboards
2018-03-26 21:13:44.701289 INFO Starting API
2018-03-26 21:13:44.711975 WARNING AppDaemon: ------------------------------------------------------------
2018-03-26 21:13:44.713216 WARNING AppDaemon: Unexpected error in api thread
2018-03-26 21:13:44.715804 WARNING AppDaemon: ------------------------------------------------------------
2018-03-26 21:13:44.723924 WARNING AppDaemon: Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/appdaemon/adapi.py", line 43, in __init__
    f = loop.create_server(handler, "0.0.0.0", int(self.api_port), ssl=context)
TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType'

2018-03-26 21:13:44.725359 WARNING AppDaemon: ------------------------------------------------------------
2018-03-26 21:13:46.007312 INFO AppDaemon: HASS: Connected to Home Assistant 0.65.6
2018-03-26 21:13:47.725443 INFO AppDaemon: Got initial state from namespace default
2018-03-26 21:13:48.659758 INFO AppDaemon: Reading config
2018-03-26 21:13:49.455132 INFO AppDaemon: /config/appdaemon/apps/apps.yaml added or modified
2018-03-26 21:13:49.456491 INFO AppDaemon: /config/appdaemon/apps/apps.yaml added or modified
2018-03-26 21:13:49.457727 INFO AppDaemon: App 'utils' added
2018-03-26 21:13:49.458754 INFO AppDaemon: App 'auto_turnoff_in_five' added
2018-03-26 21:13:49.459635 INFO AppDaemon: App 'auto_turnoff_in_ten' added
2018-03-26 21:13:49.460476 INFO AppDaemon: App 'auto_turrn_off_time' added
2018-03-26 21:13:49.461306 INFO AppDaemon: App 'auto_turnoff_front_garden' added
2018-03-26 21:13:49.462148 INFO AppDaemon: App 'auto_turn_on_off_backyard_lights' added
2018-03-26 21:13:49.463039 INFO AppDaemon: App 'auto_turnoff_motion_upstairs_gallery' added
2018-03-26 21:13:49.463883 INFO AppDaemon: App 'auto_turnon_off_motion_front_porch' added
2018-03-26 21:13:49.464715 INFO AppDaemon: App 'auto_turnoff_motion_light_study' added
2018-03-26 21:13:49.465637 INFO AppDaemon: App 'auto_turn_on_off_presence_scott' added
2018-03-26 21:13:49.466507 INFO AppDaemon: App 'auto_turn_on_off_presence_lia' added
2018-03-26 21:13:49.467399 INFO AppDaemon: App 'auto_turn_on_off_presence_emily' added
2018-03-26 21:13:49.468455 INFO AppDaemon: App 'auto_turn_on_off_presence_laura' added
2018-03-26 21:13:49.469324 INFO AppDaemon: App 'auto_turn_on_off_presence_zara' added
2018-03-26 21:13:49.470545 INFO AppDaemon: App 'auto_turn_on_off_front_garden_lights' added
2018-03-26 21:13:49.471770 INFO AppDaemon: App 'auto_turn_on_off_sunset_test' added
2018-03-26 21:13:49.472843 INFO AppDaemon: App 'study_motion_scene' added
2018-03-26 21:13:49.473755 INFO AppDaemon: App 'front_sprinkler_state_change' added
2018-03-26 21:13:49.474602 INFO AppDaemon: App 'back_sprinkler_state_change' added
2018-03-26 21:13:49.475542 INFO AppDaemon: App 'notify_door_open_closed_garage' added
2018-03-26 21:13:49.476477 INFO AppDaemon: App 'notify_door_open_closed_front' added
2018-03-26 21:13:49.478137 INFO AppDaemon: Adding /config/appdaemon/apps to module import path
2018-03-26 21:13:49.481344 INFO AppDaemon: Adding /config/appdaemon/apps/logs to module import path
2018-03-26 21:13:49.483168 INFO AppDaemon: Adding /config/appdaemon/apps/message to module import path
2018-03-26 21:13:49.496133 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/notify_state_change.py
2018-03-26 21:13:49.609266 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_on_off_presence.py
2018-03-26 21:13:49.636740 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/notify_door_open_closed.py
2018-03-26 21:13:49.643028 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_on_off_motion.py
2018-03-26 21:13:49.651762 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/xiaomi_switch.py
2018-03-26 21:13:49.658120 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_on_off_motion_lumens.py
2018-03-26 21:13:49.666999 WARNING AppDaemon: No app description found for: /config/appdaemon/apps/notify_calendar_event.py - ignoring
2018-03-26 21:13:49.668771 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/utils.py
2018-03-26 21:13:49.677433 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_off_time.py
2018-03-26 21:13:49.683530 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/sunset.py
2018-03-26 21:13:49.689395 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_on_off_sunset.py
2018-03-26 21:13:49.695563 WARNING AppDaemon: No app description found for: /config/appdaemon/apps/sound.py - ignoring
2018-03-26 21:13:49.697039 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_on_off.py
2018-03-26 21:13:49.713101 INFO AppDaemon: Loading App Module: /config/appdaemon/apps/auto_turn_off_delay.py
2018-03-26 21:13:49.726047 INFO AppDaemon: Initializing app auto_turnoff_in_five using class AutoTurnOffLightsDelay from module auto_turn_off_delay
2018-03-26 21:13:49.729580 INFO AppDaemon: Initializing app auto_turnoff_in_ten using class AutoTurnOffLightsDelay from module auto_turn_off_delay
2018-03-26 21:13:49.734281 INFO AppDaemon: Initializing app auto_turrn_off_time using class AutoTurnOffLightsTime from module auto_turn_off_time
2018-03-26 21:13:49.738795 INFO AppDaemon: Initializing app auto_turnoff_front_garden using class AutoTurnOffLightsDelay from module auto_turn_off_delay
2018-03-26 21:13:49.741572 INFO AppDaemon: Initializing app auto_turn_on_off_backyard_lights using class AutoTurnOnOffLights from module auto_turn_on_off
2018-03-26 21:13:49.744462 INFO AppDaemon: Initializing app auto_turnoff_motion_upstairs_gallery using class AutoTurnOnOffLightsMotion from module auto_turn_on_off_motion
2018-03-26 21:13:49.746724 INFO AppDaemon: Initializing app auto_turnon_off_motion_front_porch using class AutoTurnOnOffLightsMotion from module auto_turn_on_off_motion
2018-03-26 21:13:49.749083 INFO AppDaemon: Initializing app auto_turnoff_motion_light_study using class AutoTurnOnOffLightsMotionLumens from module auto_turn_on_off_motion_lumens
2018-03-26 21:13:50.587689 INFO auto_turnoff_motion_light_study: Motion on binary_sensor.study_motion working
2018-03-26 21:13:50.589182 INFO AppDaemon: Initializing app auto_turn_on_off_presence_scott using class AutoTurnOffPresence from module auto_turn_on_off_presence
2018-03-26 21:13:50.592063 INFO AppDaemon: Initializing app auto_turn_on_off_presence_lia using class AutoTurnOffPresence from module auto_turn_on_off_presence
2018-03-26 21:13:50.594767 INFO AppDaemon: Initializing app auto_turn_on_off_presence_emily using class AutoTurnOffPresence from module auto_turn_on_off_presence
2018-03-26 21:13:50.597693 INFO AppDaemon: Initializing app auto_turn_on_off_presence_laura using class AutoTurnOffPresence from module auto_turn_on_off_presence
2018-03-26 21:13:50.599912 INFO AppDaemon: Initializing app auto_turn_on_off_presence_zara using class AutoTurnOffPresence from module auto_turn_on_off_presence
2018-03-26 21:13:50.602379 INFO AppDaemon: Initializing app auto_turn_on_off_front_garden_lights using class AutoTurnOnOffSunset from module auto_turn_on_off_sunset
2018-03-26 21:13:50.605782 INFO AppDaemon: Initializing app auto_turn_on_off_sunset_test using class TurnOnOffSunset from module sunset
2018-03-26 21:13:50.608714 INFO AppDaemon: Initializing app study_motion_scene using class xiaomiSwitch from module xiaomi_switch
2018-03-26 21:13:50.623905 INFO study_motion_scene: binary_sensor.switch_158d0002109f0e
2018-03-26 21:13:50.626491 INFO AppDaemon: Initializing app front_sprinkler_state_change using class NotifyStateChange from module notify_state_change
2018-03-26 21:13:50.628718 INFO AppDaemon: Initializing app back_sprinkler_state_change using class NotifyStateChange from module notify_state_change
2018-03-26 21:13:50.630384 INFO AppDaemon: Initializing app notify_door_open_closed_garage using class NotifyDoorOpenClosed from module notify_door_open_closed
2018-03-26 21:13:50.633335 INFO AppDaemon: Initializing app utils using class utils from module utils
2018-03-26 21:13:50.635813 INFO AppDaemon: Initializing app notify_door_open_closed_front using class NotifyDoorOpenClosed from module notify_door_open_closed
2018-03-26 21:13:50.639295 INFO AppDaemon: App initialization complete
2018-03-26 21:13:58.922966 INFO auto_turnoff_motion_light_study: Motion on binary_sensor.study_motion detected
2018-03-26 21:13:58.967032 INFO auto_turnoff_motion_light_study: light 785 detected
2018-03-26 21:14:00.861534 INFO auto_turnoff_motion_light_study: Motion on binary_sensor.study_motion detected
2018-03-26 21:14:00.870390 INFO auto_turnoff_motion_light_study: light 764 detected

Please let me know if you need anymore info

thanks again.

the api port error was because you had an empty api_port in your appdaemon.yaml
that could cause trouble.

i wouldnt put logfiles in your apps dir.
the apps dir gets checked for changed files every second.
and logfiles there is very bad.

so please put them in another dir and restart your RPI.

Noticed another issue when reloading apps and not getting the new changes to be reflected after the write. This is probably related to the issue I reported from this post from one of the earlier betas here.

Consider the following app:

import appdaemon.plugins.hass.hassapi as hass
import globals

class switches(hass.Hass):
#
# testing
#
     def initialize(self):
        self.log("Initializing Test4")   <<=== Watch the number after Test
        self.listen_state(self.dummy,globals.office_heater,new="off", old="on")

     def dummy(self, entity, attribute, old, new, kwargs):
        self.log("dummy")
        return

I get the following in my log:

2018-03-26 11:07:36.423509 INFO AppDaemon: Removing module /home/homeassistant/conf/apps/t2.py
2018-03-26 11:07:36.425505 INFO AppDaemon: Terminating t2
2018-03-26 11:07:37.435671 INFO AppDaemon: Loading App Module: /home/homeassistant/conf/apps/t2.py
2018-03-26 11:07:37.437211 INFO AppDaemon: Initializing app t2 using class switches from module t2
2018-03-26 11:07:37.440724 INFO t2: Initializing Test0  <====Initial write
2018-03-26 11:07:43.495556 INFO AppDaemon: Terminating t2
2018-03-26 11:07:43.496551 INFO AppDaemon: Reloading Module: /home/homeassistant/conf/apps/t2.py
2018-03-26 11:07:43.499903 INFO AppDaemon: Initializing app t2 using class switches from module t2
2018-03-26 11:07:43.503533 INFO t2: Initializing Test1  <==== Update to Test1 and write - Works as expected!
2018-03-26 11:07:47.540311 INFO AppDaemon: Terminating t2
2018-03-26 11:07:47.541017 INFO AppDaemon: Reloading Module: /home/homeassistant/conf/apps/t2.py
2018-03-26 11:07:47.544780 INFO AppDaemon: Initializing app t2 using class switches from module t2
2018-03-26 11:07:47.548303 INFO t2: Initializing Test2 <===== Update to Test 2 and write - Works as expected!
2018-03-26 11:07:51.587811 INFO AppDaemon: Terminating t2
2018-03-26 11:07:51.588573 INFO AppDaemon: Reloading Module: /home/homeassistant/conf/apps/t2.py
2018-03-26 11:07:51.592440 INFO AppDaemon: Initializing app t2 using class switches from module t2
2018-03-26 11:07:51.595894 INFO t2: Initializing Test3 <===== Update to Test3 and write - Works as expected!
2018-03-26 11:07:56.641097 INFO AppDaemon: Removing module /home/homeassistant/conf/apps/t2.py  <===== hmmmm... - REMOVING not RELOADING????????
2018-03-26 11:07:56.642789 INFO AppDaemon: Terminating t2
2018-03-26 11:07:57.652842 INFO AppDaemon: Loading App Module: /home/homeassistant/conf/apps/t2.py
2018-03-26 11:07:57.654414 INFO AppDaemon: Initializing app t2 using class switches from module t2
2018-03-26 11:07:57.657848 INFO t2: Initializing Test3 <===== Update to Test4 and write - DID NOT UPDATE AS EXPECTED!

Somewhat random when this will occur - but I can reproduce at will.

Let me know if you need any further clarification.

Can you confirm what version you are running?

AppDaemon 3.0.0
HASS 0.65.5

2018-03-26 11:27:16.036952 INFO AppDaemon Version 3.0.0 starting
2018-03-26 11:27:16.037686 INFO Configuration read from: /home/homeassistant/conf/appdaemon.yaml
2018-03-26 11:27:16.040031 INFO AppDaemon: Starting Apps
2018-03-26 11:27:16.047776 INFO AppDaemon: Loading Plugin HASS using class HassPlugin from module hassplugin
2018-03-26 11:27:16.069757 INFO AppDaemon: HASS: HASS Plugin Initializing
2018-03-26 11:27:16.071412 INFO AppDaemon: HASS: HASS Plugin initialization complete
2018-03-26 11:27:16.073170 INFO Dashboards are disabled
2018-03-26 11:27:16.073626 INFO API is disabled
2018-03-26 11:27:16.091621 INFO AppDaemon: HASS: Connected to Home Assistant 0.65.5

After a dive through the code, I suspect that this might be caused by the way the file is being rewritten. If it is momentarily deleted, then recreated, but AD does it’s check at the exact moment it is deleted, you would observe the behavior above (unloading vs reloading), with the exception that is should have picked up the new version of the code which it clearly didn’t.

What are you using to edit the apps?

Vi - just making changes and then hitting :w

Also editing on the local machine … (same machine with HASS and AD)

1 Like

Old school - I approve :slight_smile:

I know Vi saves .swp files and makes backups etc. so it’s possible my theory is correct - I’ll give it a try locally and see if I can reproduce it.

1 Like

Hahaha - yeah I can run circles around them kids with their fancy GUI editors …:grin:

1 Like

Can;t seem to get it to happen here, even using vi - I tried about 20 times in a row.

What hardware are you using? Might be related to speed of filesystems.

Running Ubuntu on a VM on a Synology NAS. I get the delete and reloading if the file system is slow - but sure seems off that it would reload the old version of the app.

Yes, that part is clearly wrong …

I also use vim and I think I have seen similar problems, but not often enough to tie it down.

1 Like

i also noticed that it wasnt 100% reliable, but i didnt want to mention it untill i had more info (and didnt come around to it yet)
so once again eboon saves me some time :wink:

and you know already about my filesystem :wink:

1 Like

Thanks @ReneTode.
Have added the port and checked it matched the hassio AD value. Alos moved the location of the log files. Will see if this makes difference

thanks again

1 Like