Interface process crashes due to "KeyError: 'MQTT'"

I would like to report an error.

I have been able to successfully install SimpleScheduler, but its interface fails to run. See below the log with Python traceback. I have tried to uninstall and reinstall the SimpleScheduler add-on, but the problem remains.

[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... 

-----------------------------------------------------------
 Add-on: Simple Scheduler
 Simple timer on weekly base
-----------------------------------------------------------
 Add-on version: 2.5
 You are running the latest version of this add-on.
 System: Home Assistant OS 12.1  (aarch64 / raspberrypi3-64)
 Home Assistant Core: 2024.3.3
 Home Assistant Supervisor: 2024.03.1
-----------------------------------------------------------
 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... 
[cont-init.d] 01-log-level.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[21:06:22] INFO: Starting service.d [Scheduler]
[21:06:22] INFO: Starting service.d [Interface]
[21:06:22] INFO: Running interface.sh
[21:06:22] INFO: Running scheduler.sh
[2024-04-02 21:06:26] STATUS: Starting main program
Traceback (most recent call last):
  File "/simplescheduler/main.py", line 925, in <module>
    if options['MQTT']['enabled']:
KeyError: 'MQTT'
[21:06:26] WARNING: Interface process crashed...
[21:06:26] INFO: Restarting...
[21:06:26] INFO: Starting service.d [Interface]

My guess what is happening because I don't have MQTT server installed. Thus I don't have "MQTT enabled" parameter set. This causes the code to crash.

If this is correct diagnosis, it might be solved by simply adding extra check to the problematic line 925 in main.py:

    if 'MQTT' in options and options['MQTT']['enabled']:

...but I am not sure if this problem would arise also elsewhere.

My guess what is happening because I don't have MQTT server installed. Thus I don't have "MQTT enabled" parameter set. This causes the code to crash.

It is very unlikely. Every time I publish a new release, I deploy (and run) the addon on a HA fresh installation with nothing else in it.

The real (inexplicable) issue here is that the MQTT key in the configuration file is missing. But in a fresh install, the configuration file is created from a template. And the key is in the template.

Please try the following: (you should have "SAMBA" addon installed)

Uninstall the simplescheduler addon
go to the folder /share/simplescheduler and check for any content.
If any file is present, please make a copy of it elsewhere and then delete everything in the folder.
Try to reinstall the addon and test it.

Thank you for fast reply! This problem is probably then related to the fact that I have not done a clean install but I have updated from version 0.35 -> 2.5.

As you suggested, I did the following:

uninstalled the add-on
renamed the /share/simplescheduler ->/share/simplescheduler_backup
reinstalled the add-on
started (CRASH) the add-on
restarted the add-on

On the first start, the Line 882 in main.py (os.makedirs()) gave "FileExistsError: /share/simplescheduler". Strangely this should not happen as on the line above it there is a test for folder existence, but still this error came up. Are there multiple threads running, so that both of them would attempt to create the folder simultaneusly?

Anyway, the add-on seems to work for me now. However, I am not certain if all files were created to the /share/simplescheduler/ as expected. In the old folder I renamed, there were all these files:

2023-12-11  18.35               161 6224953416e42.json
2023-10-30  23.32               154 62249599b0204.json
2023-12-11  18.37               163 62249643701d3.json
2023-10-30  23.33               176 62249692b14b4.json
2023-10-28  20.46               154 623b60989b4ab.json
2023-12-11  18.36               161 62437caf096cf.json
2024-04-02  22.20               681 options.dat
2024-04-01  00.00           635 235 scheduler.log
2024-04-02  22.21         1 933 680 simplescheduler.log
2024-04-01  00.28               351 sun.dat

While the new folder was created with only single file simplescheduler.log in it. Most remarkably there is no options.dat file there at all, which I would assume should have been created. Should the sun.dat also still be there? Maybe that "FileExistsError" interrupted the file creation process?

I re-read your instructions and noticed that you instructed to remove files in folder /share/simplescheduler instead of removing the folder. I did the reinstallation again but this removed the files instead of folder. Resulting folder content is still exactly the same with single log file, but now there was no crash on first start.

However, I during this installation I noticed that after very long time the Home Assistant web page gave pop-up "Installation failed, see supervisor logs for details". This may have happened also last time, but I may not have noticed it. This popup is strange as the add-on seems to be successfully installed and the supervisor log does not show any problems:

2024-04-03 11:14:03.212 INFO (MainThread) [supervisor.addons.addon] Creating Home Assistant add-on data folder /data/addons/data/00185a40_simplescheduler
2024-04-03 11:14:03.234 INFO (MainThread) [supervisor.docker.addon] Starting build for 00185a40/aarch64-addon-simplescheduler:2.5
2024-04-03 11:21:55.639 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
2024-04-03 11:21:55.641 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
2024-04-03 11:21:56.085 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
2024-04-03 11:21:56.167 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
2024-04-03 11:21:56.171 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
2024-04-03 11:21:56.176 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
2024-04-03 11:21:56.179 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
2024-04-03 11:21:56.184 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-04-03 11:21:56.187 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
2024-04-03 11:21:56.193 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
2024-04-03 11:21:56.196 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-04-03 11:21:56.198 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
2024-04-03 11:21:58.997 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-04-03 11:21:58.000 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2024-04-03 11:21:58.002 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
2024-04-03 11:24:19.699 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-04-03 11:25:01.300 INFO (MainThread) [supervisor.updater] Fetching update data from https://version.home-assistant.io/stable.json
2024-04-03 11:25:22.269 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/michelebossa/HA-Scheduler repository
2024-04-03 11:25:22.325 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/arthurdent75/SimpleScheduler repository
2024-04-03 11:25:22.382 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/esphome/home-assistant-addon repository
2024-04-03 11:25:22.407 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/home-assistant/addons repository
2024-04-03 11:25:22.458 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/hassio-addons/repository repository
2024-04-03 11:25:48.685 INFO (MainThread) [supervisor.store] Loading add-ons from store: 79 all - 0 new - 0 remove
2024-04-03 11:25:48.688 INFO (MainThread) [supervisor.store] Loading add-ons from store: 79 all - 0 new - 0 remove
2024-04-03 11:31:58.955 INFO (MainThread) [supervisor.docker.addon] Build 00185a40/aarch64-addon-simplescheduler:2.5 done
2024-04-03 11:31:58.958 INFO (MainThread) [supervisor.addons.manager] Add-on '00185a40_simplescheduler' successfully installed

Could the issue be that something old has been left in the /data/addons/data/00185a40_simplescheduler folder from the earlier add-on version? I think that folder is not easily accessible for me to check(?).

I think I managed to get the addon to work again perfectly fine. In my tests the scheduler works now as expected. The options.data was created only once I pressed save button on the console webpage. Probably there should not be any more files created in the /share/simplescheduler folder.

However, it seems to me that there might be some things that there are three issues that might have call for to improve smooth updating and installation:

Issue: Updating and reinstalling fails in HA systems on which an old version with outdated /share/simplescheduler/options.dat has ever been installed before. Uninstall & reinstall of the add-on does not help.
- Workaround: manually remove the old options.dat via SAMBA.
- Suggested fix: The loading of options should be more robust so that if an outdated version of that file exists without some expected parameters set, the options-dict would be filled with default values.
Issue: If folder /share/simplescheduler does not exist on first start, the Line 882 in main crashed due to "FileExistsError".
- Workaround: restart the add-on and it is not a problem later
- Fix: ???
Issue: The installation of the add-on appears to fail with pop-up "Installation failed, see supervisor logs for details", while in reality the installation succeeds in the background.
- Workaround: Ignore the error pop-up
- Fix: ???

First of all, thank you @jmsuomal for all your effort in debugging. The real issue here is due to the upgrade from a version before 2.0

The 2.0 version was completely rewritten from scratch: I migrated to Python from PHP, so even the docker images have changed. This is the cause of the issues 1 and 3 you listed. There is no real fix for this. Further, it is a very rare condition nowadays. I managed this kind of issue one year ago when the 2.0 was released. I definitely will add a note in the documentation about how to manage this scenario.

I am aware of the issue n.2 . Onestly, it is a self-fixing problem because the process automatically restarts itself on crash, so usually no one sees it. This process took a couple of seconds, only on the first installation, so no one is really bothered. Anyway, I have this on my to-do list.

Thanks again for all your effort! 😃 I think this issue can be closed.

arthurdent75 / SimpleScheduler

Interface process crashes due to "KeyError: 'MQTT'" #155