Invalid callback handle

samnewman86 commented 3 years ago

A new error is appearing in the logs after updating appdaemon.

😩 Describe the issue/bug A clear and concise description of what the bug is. ppDaemon: Invalid callback handle 'dd2eb564576d4d17991938edd6095446' in cancel_timer() from app pantry_lights 😒 Expected behavior A clear and concise description of what you expected to happen. The apps to start up without erros 🎛️ Configuration

bathroom_lights:
 module: automoli
 class: AutoMoLi
 room: bathroom
 delay: 180
 motion_state_on: "on"
 motion_state_off: "off"
 disable_switch_entities: "input_boolean.bathroom_fan_bath"
 disable_switch_states: "on"
 daytimes:
 - { starttime: "05:30", name: morning, light: "scene.bathroom_morning" }
 - { starttime: "08:30", name: day, light: "scene.bathroom_daytime" }
 - { starttime: "20:30", name: evening, light: "scene.bathroom_evening" }
 - { starttime: "23:30", name: night, light: "scene.bathroom_night" }
# humidity_threshold: 75
 lights:
 - light.bathroom
 - light.mirror_light
 motion:
 - binary_sensor.tradfri_motion_sensor_3 #humidity:
# - sensor.humidity_158d0001b95fb7

hallway_lights:
 module: automoli
 class: AutoMoLi
 room: hallway
 delay: 30
 motion_state_on: "on"
 motion_state_off: "off"
 daytimes:
 - { starttime: "05:30", name: morning, light: "scene.hallmorning" }
 - { starttime: "08:30", name: day, light: "scene.hallday" }
 - { starttime: "20:30", name: evening, light: "scene.hallevening" }
 - { starttime: "22:30", name: night, light: "scene.hallnight" }
# humidity_threshold: 75
 lights:
 - light.upstairs_hall_1
 - light.upstairs_hall_2
 - light.upstairs_hall_3
 - light.upstairs_hall_4
 motion:
 - binary_sensor.motion_detector_hallway_upstairs
 - binary_sensor.tradfri_motion_sensor #humidity:
# - sensor.humidity_158d0001b95fb7

foyer_lights:
 module: automoli
 class: AutoMoLi
 room: foyer
 delay: 30
 motion_state_on: "on"
 motion_state_off: "off"
 daytimes:
 - { starttime: "05:30", name: morning, light: 10 }
 - { starttime: "08:30", name: day, light: 100 }
 - { starttime: "20:30", name: evening, light: 40 }
 - { starttime: "22:30", name: night, light: 1 }
# humidity_threshold: 75
 lights:
 - light.foyer_downlight
 motion:
 - binary_sensor.tradfri_motion_sensor_2 #humidity:
# - sensor.humidity_158d0001b95fb7
pantry_lights:
 module: automoli
 class: AutoMoLi
 room: pantry
 delay: 30
 motion_state_on: "on"
 motion_state_off: "off"
 daytimes:
 - { starttime: "05:30", name: morning, light: 100 }
 - { starttime: "08:30", name: day, light: 100 }
 - { starttime: "20:30", name: evening, light: 100 }
 - { starttime: "22:30", name: night, light: 100 }
 lights:
 - light.pantry_light
 motion: binary_sensor.tradfri_motion_pantry

🧠 System

AppDaemon: 4.06
- running mode: hassio plugin 0.5.0
Home-Assistant: 2021.3.4
- running mode: superviser 2021.03.06
Python: 3.8.7

🗒️ Logs

Add-on: AppDaemon 4 Python Apps and Dashboard using AppDaemon 4.x for Home Assistant

Add-on version: 0.5.0 You are running the latest version of this add-on. System: Debian GNU/Linux 10 (buster) (amd64 / qemux86-64) Home Assistant Core: 2021.3.4 Home Assistant Supervisor: 2021.03.6

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

[cont-init.d] 00-banner.sh: exited 0.
[cont-init.d] 01-log-level.sh: executing... 
Log level is set to DEBUG
[cont-init.d] 01-log-level.sh: exited 0.
[cont-init.d] appdaemon.sh: executing... 
[cont-init.d] appdaemon.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[15:53:02] INFO: Starting AppDaemon...
2021-03-23 15:53:02.620599 INFO AppDaemon: AppDaemon Version 4.0.6 starting
2021-03-23 15:53:02.620756 INFO AppDaemon: Python version is 3.8.8
2021-03-23 15:53:02.620900 INFO AppDaemon: Configuration read from: /config/appdaemon/appdaemon.yaml
2021-03-23 15:53:02.621066 INFO AppDaemon: Added log: AppDaemon
2021-03-23 15:53:02.621235 DEBUG AppDaemon:   filename:    STDOUT
2021-03-23 15:53:02.621710 DEBUG AppDaemon:   size:        1000000
2021-03-23 15:53:02.621837 DEBUG AppDaemon:   generations: 3
2021-03-23 15:53:02.621982 DEBUG AppDaemon:   format:      {asctime} {levelname} {appname}: {message}
2021-03-23 15:53:02.622121 INFO AppDaemon: Added log: Error
2021-03-23 15:53:02.622262 DEBUG AppDaemon:   filename:    STDERR
2021-03-23 15:53:02.622406 DEBUG AppDaemon:   size:        1000000
2021-03-23 15:53:02.622544 DEBUG AppDaemon:   generations: 3
2021-03-23 15:53:02.622682 DEBUG AppDaemon:   format:      {asctime} {levelname} {appname}: {message}
2021-03-23 15:53:02.622814 INFO AppDaemon: Added log: Access
2021-03-23 15:53:02.622950 DEBUG AppDaemon:   filename:    STDOUT
2021-03-23 15:53:02.623087 DEBUG AppDaemon:   size:        1000000
2021-03-23 15:53:02.623220 DEBUG AppDaemon:   generations: 3
2021-03-23 15:53:02.623354 DEBUG AppDaemon:   format:      {asctime} {levelname} {appname}: {message}
2021-03-23 15:53:02.623482 INFO AppDaemon: Added log: Diag
2021-03-23 15:53:02.623616 DEBUG AppDaemon:   filename:    STDOUT
2021-03-23 15:53:02.623749 DEBUG AppDaemon:   size:        1000000
2021-03-23 15:53:02.623884 DEBUG AppDaemon:   generations: 3
2021-03-23 15:53:02.624016 DEBUG AppDaemon:   format:      {asctime} {levelname} {appname}: {message}
2021-03-23 15:53:02.624205 DEBUG AppDaemon: AppDaemon Section: {'latitude': 51.78741, 'longitude': 0.629406, 'elevation': 2, 'time_zone': 'Europe/London', 'plugins': {'HASS': {'type': 'hass'}}, 'disable_apps': False, 'config_dir': '/config/appdaemon', 'config_file': '/config/appdaemon/appdaemon.yaml', 'app_config_file': '/config/appdaemon/apps.yaml', 'module_debug': {}, 'timewarp': 1, 'loglevel': 'DEBUG', 'stop_function': <bound method ADMain.stop of <appdaemon.__main__.ADMain object at 0x7fef4c6b6b20>>}
2021-03-23 15:53:02.624597 DEBUG AppDaemon: HADashboard Section: None
2021-03-23 15:53:02.637950 DEBUG AppDaemon: register_service called: admin.app.start -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.638155 DEBUG AppDaemon: register_service called: admin.app.stop -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.638349 DEBUG AppDaemon: register_service called: admin.app.restart -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.638588 DEBUG AppDaemon: register_service called: admin.app.disable -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.638772 DEBUG AppDaemon: register_service called: admin.app.enable -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.638946 DEBUG AppDaemon: register_service called: admin.app.reload -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.639110 DEBUG AppDaemon: register_service called: admin.app.create -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.639274 DEBUG AppDaemon: register_service called: admin.app.edit -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.639445 DEBUG AppDaemon: register_service called: admin.app.remove -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.639607 DEBUG AppDaemon: register_service called: admin.app.reload -> <bound method AppManagement.manage_services of <appdaemon.app_management.AppManagement object at 0x7fef4a57b7f0>>
2021-03-23 15:53:02.640010 INFO AppDaemon: Loading Plugin HASS using class HassPlugin from module hassplugin
2021-03-23 15:53:02.662473 INFO HASS: HASS Plugin Initializing
2021-03-23 15:53:02.662678 INFO HASS: HASS Plugin initialization complete
2021-03-23 15:53:02.662948 DEBUG AppDaemon: Starting thread_async loop
2021-03-23 15:53:02.663269 DEBUG AppDaemon: Starting utility loop
2021-03-23 15:53:02.663486 INFO AppDaemon: Initializing HTTP
2021-03-23 15:53:02.663809 INFO AppDaemon: Using 'ws' for event stream
2021-03-23 15:53:02.666213 INFO AppDaemon: Starting API
2021-03-23 15:53:02.668665 INFO AppDaemon: Starting Admin Interface
2021-03-23 15:53:02.668976 INFO AppDaemon: Starting Dashboards
2021-03-23 15:53:02.670942 DEBUG AppDaemon: Starting admin loop
2021-03-23 15:53:02.671165 DEBUG AppDaemon: Start Main Loop
2021-03-23 15:53:02.671583 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.671708 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'start'}
2021-03-23 15:53:02.671837 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'start'}}
2021-03-23 15:53:02.672061 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.672174 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'stop'}
2021-03-23 15:53:02.672303 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'stop'}}
2021-03-23 15:53:02.672488 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.672593 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'restart'}
2021-03-23 15:53:02.672712 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'restart'}}
2021-03-23 15:53:02.672873 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.672976 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'disable'}
2021-03-23 15:53:02.673082 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'disable'}}
2021-03-23 15:53:02.673240 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.673353 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'enable'}
2021-03-23 15:53:02.673462 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'enable'}}
2021-03-23 15:53:02.673619 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.673736 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'reload'}
2021-03-23 15:53:02.673840 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'reload'}}
2021-03-23 15:53:02.674021 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.674155 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'create'}
2021-03-23 15:53:02.674297 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'create'}}
2021-03-23 15:53:02.674538 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.674684 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'edit'}
2021-03-23 15:53:02.674831 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'edit'}}
2021-03-23 15:53:02.675054 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.675202 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'remove'}
2021-03-23 15:53:02.675351 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'remove'}}
2021-03-23 15:53:02.675569 DEBUG AppDaemon: Event type:service_registered:
2021-03-23 15:53:02.675713 DEBUG AppDaemon: {'namespace': 'admin', 'domain': 'app', 'service': 'reload'}
2021-03-23 15:53:02.675864 DEBUG AppDaemon: process_event_callbacks() admin {'event_type': 'service_registered', 'data': {'namespace': 'admin', 'domain': 'app', 'service': 'reload'}}

🧁 Additional context Add any other context about the problem here. `

samnewman86 commented 3 years ago

A few restarts of appdaemon and the error is gone. If anyone else has the same error, try a few restarts.

benleb commented 3 years ago

First, it's not an error but a warning and has no effect on the functionality. AppDaemon complains that we kill a cancel a scheduled action that doesn't exist (anymore).

That's an appdaemon thing from my sight :D they already implemented the solution, the timer_running method in 4.0.7 that allows checking if a scheduled action still exists. Unfortunately, 4.0.7 is not released currently.

The code which makes use of the method is already implemented in AutoMoLi (I use the dev branch of appdaemon) but commented until 4.0.7 is released :) 👍

samnewman86 commented 3 years ago

I'm now on appdaemon 4.07 but still getting this in the logs. Do I need to update automoli?

benleb commented 3 years ago

nope, I disabled this code part as it (obviously) created errors on appdaemon <=4.0.7... my fault 🙄✌️

I am working on AutoMoli right now and implement a proper switch which uses the new code if appdaemon is at least 4.0.7 gimme some minutes/hours 😄✌️

samnewman86 commented 3 years ago

Thanks for the update. I'll look out for it.

On Sat, 3 Apr 2021, 21:11 Ben, @.***> wrote:

nope, I disabled this code part as it (obviously) created errors on appdaemon <=4.0.7... my fault 🙄✌️

I am working on AutoMoli right now and implement a proper switch which uses the new code if appdaemon is at least 4.0.7 gimme some minutes/hours 😄✌️

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/benleb/ad-automoli/issues/69#issuecomment-812919246, or unsubscribe https://github.com/notifications/unsubscribe-auth/AMUT5GOO6PMQFZXQKZXS7MDTG5Y5ZANCNFSM4ZVOYY3A .

benleb / ad-automoli