respawn does not occur if permission denied

Bug #1050073 reported by Greg Smolyn
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
upstart
New
Undecided
Unassigned

Bug Description

Occasionally, if a file is getting overwritten during a respawn, upstart may fail to run the file. However, it will not continue to attempt respawns, it only tries one attempt.

The message seen in /var/log/messages is

Sep 12 14:39:59 my-vm kernel: [246447.263602] init: mydaemon main process ended, respawning
Sep 12 14:39:59 my-vm kernel: [246447.268044] init: Failed to spawn mydaemon main process: unable to execute: Permission denied

The scenario can be easily be reproduced by

1. start mydaemon
2. chmod a-x /usr/bin/mydaemon
3. kill `pidof mydaemon`
4. sleep some amount of time (5-8 seconds), long enough to get it to notice it needs to respawn
5. chmod a+x /usr/bin/mydaemon

I tried without a respawn limit, as well as with a respawn limit set to an enormous number of allowable respawns.

Expected behaviour would be that upstart would continue to retry.

NOTE:
The chmod example is a bit contrived, however seems to show the same symptoms. The actual problem is usually caused when a new file is being copied in place of the new one (through a CMake build 'make install'). (on our system the daemon notices that this update has occurred and exits, expecting to be restarted by upstart).

Greg Smolyn (smolyn)
description: updated
description: updated
Revision history for this message
Greg Smolyn (smolyn) wrote :

I turned debug logging on, here's what I saw:

Sep 13 11:01:17 my-vm kernel: [260144.570480] init: mydaemon main process (31494) exited normally
Sep 13 11:01:17 my-vm kernel: [260144.570528] init: mydaemon main process ended, respawning
Sep 13 11:01:17 my-vm kernel: [260144.570678] init: mydaemon state changed from running to stopping
Sep 13 11:01:17 my-vm kernel: [260144.570816] init: Handling stopping event
Sep 13 11:01:17 my-vm kernel: [260144.570958] init: mydaemon state changed from stopping to killed
Sep 13 11:01:17 my-vm kernel: [260144.571013] init: mydaemon state changed from killed to post-stop
Sep 13 11:01:17 my-vm kernel: [260144.571067] init: mydaemon state changed from post-stop to starting
Sep 13 11:01:17 my-vm kernel: [260144.571158] init: Handling starting event
Sep 13 11:01:17 my-vm kernel: [260144.571264] init: mydaemon state changed from starting to pre-start
Sep 13 11:01:17 my-vm kernel: [260144.571318] init: mydaemon state changed from pre-start to spawned
Sep 13 11:01:17 my-vm kernel: [260144.575151] init: Failed to spawn mydaemon main process: unable to execute: Permission denied
Sep 13 11:01:17 my-vm kernel: [260144.576028] init: mydaemon goal changed from start to stop
Sep 13 11:01:17 my-vm kernel: [260144.576094] init: mydaemon state changed from spawned to stopping
Sep 13 11:01:17 my-vm kernel: [260144.576302] init: Handling stopping event
Sep 13 11:01:17 my-vm kernel: [260144.577383] init: mydaemon state changed from stopping to killed
Sep 13 11:01:17 my-vm kernel: [260144.578249] init: mydaemon state changed from killed to post-stop
Sep 13 11:01:17 my-vm kernel: [260144.578478] init: mydaemon state changed from post-stop to waiting
Sep 13 11:01:17 my-vm kernel: [260144.579067] init: Handling stopped event

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.