AppDaemon
AttributeError for REST endpoint sometimes after a restart
What happened?
I'm running AppDaemon in a Docker container that's run by an LXC container on my Proxmox instance. Sometimes after Proxmox runs the backup routine at night, which involves stopping the VMs and containers, AppDaemon logs an AttributeError regarding the REST endpoint of my app.
The backups are daily but the error doesn't seem to always happen with a few days in between usually. The Docker LXC gets started after my Home Assistant VM after Proxmox finished the backups.
I've had this issue for quite a while (goes back to March) so it shouldn't be related to the recent updates.
Version
4.5.7
Installation type
Docker container
Relevant log output
2025-05-31 01:01:46.773028 ERROR Error: ===========================================================================
2025-05-31 01:01:46.772400 ERROR Error: apps/manga_tracker/manga_tracker.yaml
2025-05-31 01:01:46.772222 ERROR Error: all dependencies: {'anilist_auth'}
2025-05-31 01:01:46.772006 ERROR Error: DependencyNotRunning: 'anilist' depends on 'anilist_auth', but it's not running
2025-05-31 01:01:46.771182 ERROR Error: AppStartFailure: App 'anilist' failed to start
2025-05-31 01:01:46.770962 ERROR Error: ===== Failed to start 'anilist' =========================================
2025-05-31 01:01:46.770487 ERROR Error: ===========================================================================
2025-05-31 01:01:46.770263 ERROR Error: raise AttributeError(f"The given endpoint '{endpoint}' already exists and used by {app_name}")
2025-05-31 01:01:46.770047 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/http.py", line 917, in register_endpoint
2025-05-31 01:01:46.769817 ERROR Error: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-31 01:01:46.769354 ERROR Error: return await self.AD.http.register_endpoint(callback, endpoint, self.name, **kwargs)
2025-05-31 01:01:46.769185 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/adapi.py", line 1298, in register_endpoint
2025-05-31 01:01:46.769020 ERROR Error: raise self._exception
2025-05-31 01:01:46.768847 ERROR Error: File "/usr/lib/python3.12/concurrent/futures/_base.py", line 401, in __get_result
2025-05-31 01:01:46.768649 ERROR Error: ^^^^^^^^^^^^^^^^^^^
2025-05-31 01:01:46.768484 ERROR Error: return self.__get_result()
2025-05-31 01:01:46.768313 ERROR Error: File "/usr/lib/python3.12/concurrent/futures/_base.py", line 456, in result
2025-05-31 01:01:46.768120 ERROR Error: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-31 01:01:46.767952 ERROR Error: return future.result(timeout.total_seconds())
2025-05-31 01:01:46.767777 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/utils.py", line 580, in run_coroutine_threadsafe
2025-05-31 01:01:46.767601 ERROR Error: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-31 01:01:46.767448 ERROR Error: return run_coroutine_threadsafe(self, coro, timeout=timeout)
2025-05-31 01:01:46.767282 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/utils.py", line 243, in wrapper
2025-05-31 01:01:46.767105 ERROR Error: self.adapi.register_endpoint(
2025-05-31 01:01:46.766926 ERROR Error: File "/conf/apps/manga_tracker/anilist_auth.py", line 30, in initialize
2025-05-31 01:01:46.766745 ERROR Error: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-31 01:01:46.766585 ERROR Error: result = self.fn(*self.args, **self.kwargs)
2025-05-31 01:01:46.766404 ERROR Error: File "/usr/lib/python3.12/concurrent/futures/thread.py", line 59, in run
2025-05-31 01:01:46.766220 ERROR Error: ^^^^^^^^^^^^
2025-05-31 01:01:46.766038 ERROR Error: return await future
2025-05-31 01:01:46.765849 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/utils.py", line 554, in run_in_executor
2025-05-31 01:01:46.765644 ERROR Error: await utils.run_in_executor(self, init_func)
2025-05-31 01:01:46.765439 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/app_management.py", line 289, in initialize_app
2025-05-31 01:01:46.765249 ERROR Error: await self.initialize_app(app_name)
2025-05-31 01:01:46.765026 ERROR Error: File "/usr/local/lib/python3.12/site-packages/appdaemon/app_management.py", line 392, in start_app
2025-05-31 01:01:46.762118 ERROR Error: AttributeError: The given endpoint 'mt-anilist-access-token' already exists and used by anilist_auth
2025-05-31 01:01:46.761207 ERROR Error: InitializationFail: initialize() method failed for app 'anilist_auth'
2025-05-31 01:01:46.751620 ERROR Error: AppStartFailure: App 'anilist_auth' failed to start
2025-05-31 01:01:46.751257 ERROR Error: ===== Failed to start 'anilist_auth' ====================================
Relevant code in the app or config file that caused the issue
YAML for relevant apps:
anilist:
module: "anilist"
class: "AniList"
log: "diag_log"
dependencies:
- anilist_auth
anilist_auth:
module: "anilist_auth"
class: "AniListAuth"
log: "diag_log"
client_id: !secret anilist_client_id
client_secret: !secret anilist_client_secret
redirect_url: !secret anilist_redirect_url
Endpoint registration in the anilist_auth app:
class AniListAuth(ADBase):
def initialize(self) -> None:
...
self.adapi.register_endpoint(
self.request_access_token,
"mt-anilist-access-token",
)
Anything else?
No response
This is a weird one - after a quick code review, the only way I can see this happening is if more than one app is trying to register the same endpoint, Do you have multiple apps registering endpoints? If you are truly restarting Appdaemon, it should start fresh with the endpoints, and when an app is terminated all of it's endpoints are cleared out.
This is the only place where I register an endpoint and this app only has one instance too. I'll have to see, if I can find anything on my site. I'd expect it to properly stop and restart as that's what I instructed Proxmox to do:
OK, lets get some AppDaemon logging for the time period in question when you see the issue - that should show us the shutdown is occurring properly, and might highlight anything weird with a double start or something like that.
Added some more logs as it apparently happened today too. But to me it doesn't look like AppDaemon was even shut down
appdaemon-main.log appdaemon-error.log
Yeah, so what I see in those logs is HASS shutdown, AD having some issues connecting, then the REST error ... THEN AD is restarted.
Maybe if you can enforce shutting down AD before HASS it would help?
Looking at my Proxmox logs, I think the backups is performed in this order:
- Shut down my HA VM (this seems to be the part where AD disconnects)
- Back up the HA VM
- Start the HA VM again (this is where the REST error happens)
- Repeat process for the AD container etc.
So it's completely sequential and I can't seem to specify the order which probably wouldn't help either. How does AD handle dis-/reconnects to HA? From the looks it doesn't seem like the apps where stopped with the disconnect but it tries to initialize them when reconnecting which might be why the error happens?
Maybe this would help:
if (self.rest_handle is not None):
self.rest_handle = self.adapi.register_endpoint(
self.request_access_token,
"mt-anilist-access-token",
)
But the handling on AD site seems weird to me
AD should handle this just fine - despite the look of the logs, it's just this one error that is upsetting things, and then causing follow-on errors when your app doesn't initialize properly. We will keep looking.
It just seemed weird to me that the error seemingly happened before AD even restarted and instead while dis- and reconnected to HA. I'll try out the snippet I posted and see if that helps things
Let me know how it goes, we will see if there is anything we can do to make shutdown and restart more graceful in this situation.
I've got some more logs that paint the sequence a bit better. My backup routine in Proxmox logged the following which matches the timestamps in the AD log:
Jun 13 01:00:05 server-main pvescheduler[2696292]: INFO: Starting Backup of VM 100 (qemu)
Jun 13 01:00:22 server-main pvescheduler[2696292]: VM 100 started with PID 2696439.
Jun 13 01:05:18 server-main pvescheduler[2696292]: INFO: Finished Backup of VM 100 (00:05:13)
Jun 13 01:05:18 server-main pvescheduler[2696292]: INFO: Starting Backup of VM 101 (lxc)
Jun 13 01:06:22 server-main pvescheduler[2696292]: INFO: Finished Backup of VM 101 (00:01:04)
VM 100 being the HA VM and VM 101 is my Docker stuff with AD
- AD disconnected from HA at "01:00:10" which matches the start of the HA backup
- HA seems to be fully restarted around "01:01:39"
What I don't understand is why between the HA disconnect and full restart the apps seem to be initialized two times with the second time being the one that causes anilist_auth to fail. Maybe that information helps a bit