hsakoh / switchbot-mqtt

SwitchBot MQTT Home Assistant add-on
MIT License
40 stars 1 forks source link

MQTT Core Service and Polling Service dont start automatically #39

Closed JonasKruse1 closed 1 week ago

JonasKruse1 commented 2 weeks ago

Hi, first of all I love the MQTT Integration for my switchbot its much faster than the bluetooth one but every time my HA or just the integration is restarted (for whatever reason) the MQTTCore Service and Polling Service don't start and I need to go into the Web UI and start them manually which is at least once a day for me which kinda defeats the purpose of having a SmartHome right? Here are the logs I can't really see a reason why its not starting.

Use "ngrok [command] --help" for more information about a command. 09:58:36 fail: SwitchBotMqttApp.Services.WebhookService[0] StartAsync failed. System.Threading.Tasks.TaskCanceledException: A task was canceled. at FluffySpoon.Ngrok.NgrokProcess.StartAsync() at FluffySpoon.Ngrok.NgrokService.InitializeAsync(CancellationToken cancellationToken) at SwitchBotMqttApp.Services.WebhookService.StartAsync(CancellationToken cancellationToken) in C:\github\hsakoh\switchbot-mqtt\src\SwitchBotMqttApp\Services\WebhookService.cs:line 48 09:58:39 info: SwitchBotMqttApp.Services.WebhookService[0] stopped 09:59:53 info: SwitchBotMqttApp.Logics.DeviceConfigurationManager[0] device configuration file found. 3,0 09:59:55 info: SwitchBotMqttApp.Logics.DeviceConfigurationManager[0] device configuration file found. 3,0 10:00:25 trce: SwitchBotMqttApp.Logics.SwitchBotApiClient[0] Send GET,devices,(null) 10:00:27 trce: SwitchBotMqttApp.Logics.SwitchBotApiClient[0] Response GET,https://api.switch-bot.com/v1.1/devices,{"statusCode":100,"body":{"deviceList":[{"deviceId":"C166A55B6853","deviceName":"Hub Mini 53","deviceType":"Hub Mini","enableCloudService":false,"hubDeviceId":""},{"deviceId":"D56BE746816F","deviceName":"Bot 6F","deviceType":"Bot","enableCloudService":true,"hubDeviceId":"C166A55B6853"},{"deviceId":"E6A36FC5D0BD","deviceName":"Hub Mini Bedroom","deviceType":"Hub Mini","enableCloudService":false,"hubDeviceId":""}],"infraredRemoteList":[]},"message":"success"} 10:00:30 info: SwitchBotMqttApp.Logics.DeviceConfigurationManager[0] device configuration file found. 3,0 10:00:34 info: Microsoft.Hosting.Lifetime[0] Application is shutting down... 10:00:34 dbug: SwitchBotMqttApp.Services.AutomatedHostedService[0] Application has stopped - will stop services 10:00:34 info: SwitchBotMqttApp.Services.PollingService[0] stopped 10:00:34 info: SwitchBotMqttApp.Services.WebhookService[0] stopped 10:00:34 info: SwitchBotMqttApp.Services.MqttCoreService[0] stopped 10:00:50 info: Microsoft.Hosting.Lifetime[14] Now listening on: http://[::]:8098 10:00:50 info: Microsoft.Hosting.Lifetime[14] Now listening on: http://[::]:8099 10:00:50 info: Microsoft.Hosting.Lifetime[0] Application started. Press Ctrl+C to shut down. 10:00:50 info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production 10:00:50 info: Microsoft.Hosting.Lifetime[0] Content root path: /app 10:01:54 info: SwitchBotMqttApp.Logics.DeviceConfigurationManager[0] device configuration file found. 3,0 10:01:54 trce: SwitchBotMqttApp.Logics.SwitchBotApiClient[0] Send GET,devices/D56BE746816F/status,(null) 10:01:54 warn: SwitchBotMqttApp.Services.PollingService[0] MqttCoreService has not started 10:01:56 info: SwitchBotMqttApp.Services.PollingService[0] stopped 10:01:56 trce: SwitchBotMqttApp.Logics.SwitchBotApiClient[0] Response GET,https://api.switch-bot.com/v1.1/devices/D56BE746816F/status,{"statusCode":100,"body":{"deviceId":"D56BE746816F","deviceType":"Bot","hubDeviceId":"C166A55B6853","version":"V4.9","power":"off","battery":85,"deviceMode":"pressMode"},"message":"success"} 10:01:56 trce: SwitchBotMqttApp.Logics.SwitchBotApiClient[0] Send GET,scenes,(null) 10:01:56 warn: SwitchBotMqttApp.Services.PollingService[0] MqttCoreService has not started 10:01:57 trce: SwitchBotMqttApp.Logics.SwitchBotApiClient[0] Response GET,https://api.switch-bot.com/v1.1/scenes,{"statusCode":100,"body":[],"message":"success"} 10:01:57 info: SwitchBotMqttApp.Services.MqttCoreService[0] started 10:01:57 info: SwitchBotMqttApp.Services.PollingService[0] stopped 10:01:58 info: SwitchBotMqttApp.Services.PollingService[0] started 10:05:28 info: Microsoft.Hosting.Lifetime[0] Application is shutting down... 10:05:28 dbug: SwitchBotMqttApp.Services.AutomatedHostedService[0] Application has stopped - will stop services 10:05:28 info: SwitchBotMqttApp.Services.PollingService[0] stopped 10:05:28 info: SwitchBotMqttApp.Services.MqttCoreService[0] stopped 10:05:28 info: SwitchBotMqttApp.Services.WebhookService[0] stopped 10:05:30 info: Microsoft.Hosting.Lifetime[14] Now listening on: http://[::]:8098 10:05:30 info: Microsoft.Hosting.Lifetime[14] Now listening on: http://[::]:8099 10:05:30 info: Microsoft.Hosting.Lifetime[0] Application started. Press Ctrl+C to shut down. 10:05:30 info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production 10:05:30 info: Microsoft.Hosting.Lifetime[0] Content root path: /app 10:05:49 info: Microsoft.Hosting.Lifetime[0] Application is shutting down... 10:05:49 dbug: SwitchBotMqttApp.Services.AutomatedHostedService[0] Application has stopped - will stop services 10:05:49 info: SwitchBotMqttApp.Services.MqttCoreService[0] stopped 10:05:49 info: SwitchBotMqttApp.Services.PollingService[0] stopped 10:05:49 info: SwitchBotMqttApp.Services.WebhookService[0] stopped 10:05:52 info: Microsoft.Hosting.Lifetime[14] Now listening on: http://[::]:8098 10:05:52 info: Microsoft.Hosting.Lifetime[14] Now listening on: http://[::]:8099 10:05:52 info: Microsoft.Hosting.Lifetime[0] Application started. Press Ctrl+C to shut down. 10:05:52 info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production 10:05:52 info: Microsoft.Hosting.Lifetime[0] Content root path: /app

hsakoh commented 2 weeks ago

I checked the log you provided. The direct cause seems to be that during the startup of the WebhookService, the Ngrok startup failed, causing the entire service to stop, which in turn led to the shutdown of all internal services. (It seems that the Ngrok download was successful.)

Are you able to capture logs from just before the first line of the log?

Also, are you using the Webhook? If you are not using it, I think you can avoid this issue by setting UseWebhook=false or UseNgrok=false.

hsakoh commented 2 weeks ago

If the log output is too large and you cannot successfully capture the logs before WebhookService[0] StartAsync... If the same result occurs when manually starting the Webhook service, it would be helpful to have the logs from that time.

If you wish to use Webhook,Since it seems to be an issue related to starting the Ngrok process, it may be necessary to increase the log level of the internal library for a more detailed investigation. (This configuration cannot be done from the add-on options, so a dedicated add-on image would need to be provided.)

Which architecture is the hardware where the add-on is installed? Is it one of these: arm64, armv7, amd64...? Also, what installation method are you using? Is it an add-on installation on Home Assistant OS?

hsakoh commented 2 weeks ago

As additional information, I found the following patterns where the same error occurs:

hsakoh commented 1 week ago

No response, so I close it. Reopen if necessary.