It is reproducible on a clean VM and LXD container.
I guess we have a small data-race during services startup.
I added echo $(date) to maas-rack-controller.postinst just before the line where we call chown
```
+ echo Wed Mar 13 08:55:50 UTC 2024
Wed Mar 13 08:55:50 UTC 2024
```
After inspecting `journalctl -u maas-rackd` it is clear that the first attempt to start rackd happens before the maas-rack-controller.postinst script finishes execution.
Mar 13 08:55:46 maas-deb systemd[1]: Starting MAAS Rack Controller...
Mar 13 08:55:46 maas-deb systemd[1]: Started MAAS Rack Controller.
Mar 13 08:55:47 maas-deb rackd[72993]: Traceback (most recent call last):
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/sbin/rackd", line 33, in <module>
Mar 13 08:55:47 maas-deb rackd[72993]: sys.exit(load_entry_point('maas==3.5.0rc1', 'console_scripts', 'rackd')())
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/provisioningserver/server.py", line 95, in run
Mar 13 08:55:47 maas-deb rackd[72993]: runService("maas-rackd")
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/provisioningserver/server.py", line 90, in runService
Mar 13 08:55:47 maas-deb rackd[72993]: UnixApplicationRunner(config).run()
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/twisted/application/app.py", line 370, in run
Mar 13 08:55:47 maas-deb rackd[72993]: self.application = self.createOrGetApplication()
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/twisted/application/app.py", line 432, in createOrGetApplication
Mar 13 08:55:47 maas-deb rackd[72993]: ser = plg.makeService(self.config.subOptions)
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/provisioningserver/plugin.py", line 241, in makeService
Mar 13 08:55:47 maas-deb rackd[72993]: install_boot_method_templates(tftp_root)
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/provisioningserver/boot/__init__.py", line 367, in install_boot_method_templates
Mar 13 08:55:47 maas-deb rackd[72993]: m.install_templates(tftp_root)
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/python3/dist-packages/provisioningserver/boot/ipxe.py", line 118, in install_templates
Mar 13 08:55:47 maas-deb rackd[72993]: with open(config_dst, "wb") as stream:
Mar 13 08:55:47 maas-deb rackd[72993]: PermissionError: [Errno 13] Permission denied: '/var/lib/maas/tftp_root/ipxe.cfg'
Mar 13 08:55:47 maas-deb systemd[1]: maas-rackd.service: Main process exited, code=exited, status=1/FAILURE
Mar 13 08:55:47 maas-deb systemd[1]: maas-rackd.service: Failed with result 'exit-code'.
Mar 13 08:55:57 maas-deb systemd[1]: maas-rackd.service: Scheduled restart job, restart counter is at 1.
Mar 13 08:55:57 maas-deb systemd[1]: Stopped MAAS Rack Controller.
Mar 13 08:55:57 maas-deb systemd[1]: Starting MAAS Rack Controller...
Mar 13 08:55:57 maas-deb systemd[1]: Started MAAS Rack Controller.
Mar 13 08:56:50 maas-deb systemd[1]: Stopping MAAS Rack Controller...
Mar 13 08:56:50 maas-deb systemd[1]: maas-rackd.service: Deactivated successfully.
Mar 13 08:56:50 maas-deb systemd[1]: Stopped MAAS Rack Controller.
Mar 13 08:56:50 maas-deb systemd[1]: Starting MAAS Rack Controller...
Mar 13 08:56:50 maas-deb systemd[1]: Started MAAS Rack Controller.
This might happen because of maas-region-controller.postinst trying to start rackd (when both are installed on the same machine)
It is reproducible on a clean VM and LXD container.
I guess we have a small data-race during services startup.
I added echo $(date) to maas-rack- controller. postinst just before the line where we call chown
```
+ echo Wed Mar 13 08:55:50 UTC 2024
Wed Mar 13 08:55:50 UTC 2024
```
After inspecting `journalctl -u maas-rackd` it is clear that the first attempt to start rackd happens before the maas-rack- controller. postinst script finishes execution.
Mar 13 08:55:46 maas-deb systemd[1]: Starting MAAS Rack Controller... load_entry_ point(' maas==3. 5.0rc1' , 'console_scripts', 'rackd')()) python3/ dist-packages/ provisioningser ver/server. py", line 95, in run "maas-rackd" ) python3/ dist-packages/ provisioningser ver/server. py", line 90, in runService Runner( config) .run() python3/ dist-packages/ twisted/ application/ app.py" , line 370, in run tApplication( ) python3/ dist-packages/ twisted/ application/ app.py" , line 432, in createOrGetAppl ication (self.config. subOptions) python3/ dist-packages/ provisioningser ver/plugin. py", line 241, in makeService boot_method_ templates( tftp_root) python3/ dist-packages/ provisioningser ver/boot/ __init_ _.py", line 367, in install_ boot_method_ templates templates( tftp_root) python3/ dist-packages/ provisioningser ver/boot/ ipxe.py" , line 118, in install_templates maas/tftp_ root/ipxe. cfg'
Mar 13 08:55:46 maas-deb systemd[1]: Started MAAS Rack Controller.
Mar 13 08:55:47 maas-deb rackd[72993]: Traceback (most recent call last):
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/sbin/rackd", line 33, in <module>
Mar 13 08:55:47 maas-deb rackd[72993]: sys.exit(
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: runService(
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: UnixApplication
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: self.application = self.createOrGe
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: ser = plg.makeService
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: install_
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: m.install_
Mar 13 08:55:47 maas-deb rackd[72993]: File "/usr/lib/
Mar 13 08:55:47 maas-deb rackd[72993]: with open(config_dst, "wb") as stream:
Mar 13 08:55:47 maas-deb rackd[72993]: PermissionError: [Errno 13] Permission denied: '/var/lib/
Mar 13 08:55:47 maas-deb systemd[1]: maas-rackd.service: Main process exited, code=exited, status=1/FAILURE
Mar 13 08:55:47 maas-deb systemd[1]: maas-rackd.service: Failed with result 'exit-code'.
Mar 13 08:55:57 maas-deb systemd[1]: maas-rackd.service: Scheduled restart job, restart counter is at 1.
Mar 13 08:55:57 maas-deb systemd[1]: Stopped MAAS Rack Controller.
Mar 13 08:55:57 maas-deb systemd[1]: Starting MAAS Rack Controller...
Mar 13 08:55:57 maas-deb systemd[1]: Started MAAS Rack Controller.
Mar 13 08:56:50 maas-deb systemd[1]: Stopping MAAS Rack Controller...
Mar 13 08:56:50 maas-deb systemd[1]: maas-rackd.service: Deactivated successfully.
Mar 13 08:56:50 maas-deb systemd[1]: Stopped MAAS Rack Controller.
Mar 13 08:56:50 maas-deb systemd[1]: Starting MAAS Rack Controller...
Mar 13 08:56:50 maas-deb systemd[1]: Started MAAS Rack Controller.
This might happen because of maas-region- controller. postinst trying to start rackd (when both are installed on the same machine)