When sshd exits because of a bad configuration, upstart claims the job is in "start/running" with no PID

[Patrick Lee]

Reproducible on 14.04 and 14.10

In ssh's upstart config file, "expect stop" is used to signal upstart when sshd is ready to accept connections. If the sshd config file is broken, sshd terminates before it sends SIGSTOP to itself and this seems to confuse upstart, such that it thinks the ssh job is still in start/running state (with no associated PID.) In addition, I have another upstart job set to trigger on "start on stopped ssh RESULT=failed" which does _not_ trigger in this situation.

If I comment out the "expect stop" stanza from ssh.conf then the sshd process properly ends up in "stop/waiting" and my other job triggers properly.

Here is the DEBUG output from init when I start ssh with purposely broken sshd_config file

Jul 19 16:47:43 patrick-vm kernel: [956961.180770] init: ssh goal changed from stop to start
Jul 19 16:47:43 patrick-vm kernel: [956961.181056] init: ssh state changed from waiting to starting
Jul 19 16:47:43 patrick-vm kernel: [956961.181333] init: event_new: Pending starting event
Jul 19 16:47:43 patrick-vm kernel: [956961.181373] init: Handling starting event
Jul 19 16:47:43 patrick-vm kernel: [956961.181535] init: event_finished: Finished starting event
Jul 19 16:47:43 patrick-vm kernel: [956961.181548] init: ssh state changed from starting to security-spawning
Jul 19 16:47:43 patrick-vm kernel: [956961.181814] init: ssh state changed from security-spawning to security
Jul 19 16:47:43 patrick-vm kernel: [956961.182570] init: ssh state changed from security to pre-starting
Jul 19 16:47:43 patrick-vm kernel: [956961.183593] init: ssh pre-start process (43674)
Jul 19 16:47:43 patrick-vm kernel: [956961.183915] init: ssh state changed from pre-starting to pre-start
Jul 19 16:47:43 patrick-vm kernel: [956961.187572] init: ssh pre-start process (43674) exited normally
Jul 19 16:47:43 patrick-vm kernel: [956961.187664] init: ssh state changed from pre-start to spawning
Jul 19 16:47:43 patrick-vm kernel: [956961.188352] init: ssh main process (43676)
Jul 19 16:47:43 patrick-vm kernel: [956961.188512] init: ssh state changed from spawning to spawned
Jul 19 16:47:43 patrick-vm kernel: [956961.193436] init: ssh main process (43676) terminated with status 255
Jul 19 16:47:43 patrick-vm kernel: [956961.193467] init: ssh main process ended, respawning
Jul 19 16:47:43 patrick-vm kernel: [956961.193531] init: ssh state changed from spawned to post-starting
Jul 19 16:47:43 patrick-vm kernel: [956961.193896] init: ssh state changed from post-starting to post-start
Jul 19 16:47:43 patrick-vm kernel: [956961.194419] init: ssh state changed from post-start to running
Jul 19 16:47:43 patrick-vm kernel: [956961.194668] init: event_new: Pending started event
Jul 19 16:47:43 patrick-vm kernel: [956961.194795] init: Handling started event
Jul 19 16:47:43 patrick-vm kernel: [956961.194886] init: job_register: Registered instance /com/ubuntu/Upstart/jobs/startpar_2dbridge/ssh_2d_2dstarted
Jul 19 16:47:43 patrick-vm kernel: [956961.194976] init: job_register: Registered instance /com/ubuntu/Upstart/jobs/startpar_2dbridge/ssh_2d_2dstarted
Jul 19 16:47:43 patrick-vm kernel: [956961.195058] init: job_register: Registered instance /com/ubuntu/Upstart/jobs/startpar_2dbridge/ssh_2d_2dstarted
Jul 19 16:47:43 patrick-vm kernel: [956961.195164] init: job_register: Registered instance /com/ubuntu/Upstart/jobs/startpar_2dbridge/ssh_2d_2dstarted
Jul 19 16:47:43 patrick-vm kernel: [956961.195256] init: job_register: Registered instance /com/ubuntu/Upstart/jobs/startpar_2dbridge/ssh_2d_2dstarted
Jul 19 16:47:43 patrick-vm kernel: [956961.195314] init: job_class_induct_job: New instance startpar-bridge (ssh--started)
Jul 19 16:47:43 patrick-vm kernel: [956961.195333] init: startpar-bridge (ssh--started) goal changed from stop to start
Jul 19 16:47:43 patrick-vm kernel: [956961.195634] init: startpar-bridge (ssh--started) state changed from waiting to starting
Jul 19 16:47:43 patrick-vm kernel: [956961.195960] init: event_new: Pending starting event
Jul 19 16:47:43 patrick-vm kernel: [956961.196154] init: Handling starting event
Jul 19 16:47:43 patrick-vm kernel: [956961.196230] init: event_finished: Finished starting event
Jul 19 16:47:43 patrick-vm kernel: [956961.196238] init: startpar-bridge (ssh--started) state changed from starting to security-spawning
Jul 19 16:47:43 patrick-vm kernel: [956961.196459] init: startpar-bridge (ssh--started) state changed from security-spawning to security
Jul 19 16:47:43 patrick-vm kernel: [956961.196667] init: startpar-bridge (ssh--started) state changed from security to pre-starting
Jul 19 16:47:43 patrick-vm kernel: [956961.196864] init: startpar-bridge (ssh--started) state changed from pre-starting to pre-start
Jul 19 16:47:43 patrick-vm kernel: [956961.197058] init: startpar-bridge (ssh--started) state changed from pre-start to spawning
Jul 19 16:47:43 patrick-vm kernel: [956961.197616] init: startpar-bridge (ssh--started) main process (43677)
Jul 19 16:47:43 patrick-vm kernel: [956961.197778] init: startpar-bridge (ssh--started) state changed from spawning to spawned
Jul 19 16:47:43 patrick-vm kernel: [956961.199136] init: startpar-bridge (ssh--started) state changed from spawned to post-starting
Jul 19 16:47:43 patrick-vm kernel: [956961.199455] init: startpar-bridge (ssh--started) state changed from post-starting to post-start
Jul 19 16:47:43 patrick-vm kernel: [956961.199734] init: startpar-bridge (ssh--started) state changed from post-start to running
Jul 19 16:47:43 patrick-vm kernel: [956961.199994] init: event_new: Pending started event
Jul 19 16:47:43 patrick-vm kernel: [956961.200048] init: startpar-bridge (ssh--started) main process (43677) exited normally
Jul 19 16:47:43 patrick-vm kernel: [956961.200165] init: startpar-bridge (ssh--started) goal changed from start to stop
Jul 19 16:47:43 patrick-vm kernel: [956961.200421] init: startpar-bridge (ssh--started) state changed from running to stopping
Jul 19 16:47:43 patrick-vm kernel: [956961.200683] init: event_new: Pending stopping event
Jul 19 16:47:43 patrick-vm kernel: [956961.200706] init: Handling started event
Jul 19 16:47:43 patrick-vm kernel: [956961.200903] init: event_finished: Finished started event
Jul 19 16:47:43 patrick-vm kernel: [956961.201160] init: Handling stopping event
Jul 19 16:47:43 patrick-vm kernel: [956961.201275] init: event_finished: Finished stopping event
Jul 19 16:47:43 patrick-vm kernel: [956961.201285] init: startpar-bridge (ssh--started) state changed from stopping to killed
Jul 19 16:47:43 patrick-vm kernel: [956961.201520] init: startpar-bridge (ssh--started) state changed from killed to post-stopping
Jul 19 16:47:43 patrick-vm kernel: [956961.201756] init: startpar-bridge (ssh--started) state changed from post-stopping to post-stop
Jul 19 16:47:43 patrick-vm kernel: [956961.202233] init: startpar-bridge (ssh--started) state changed from post-stop to waiting
Jul 19 16:47:43 patrick-vm kernel: [956961.202498] init: event_new: Pending stopped event
Jul 19 16:47:43 patrick-vm kernel: [956961.202528] init: job_change_state: Destroyed inactive instance startpar-bridge (ssh--started)
Jul 19 16:47:43 patrick-vm kernel: [956961.203037] init: Handling stopped event
Jul 19 16:47:43 patrick-vm kernel: [956961.203173] init: event_finished: Finished stopped event
Jul 19 16:47:43 patrick-vm kernel: [956961.203446] init: event_finished: Finished started event

My goal is to have an upstart job trigger in the event that sshd_config is broken and do something helpful , e.g. start another sshd on another port with a known good config so I can get back into the box to fix the problem.

[Ubuntu Foundations Team Bug Bot (crichton)]

Thank you for taking the time to report this bug and helping to make Ubuntu better. It seems that your bug report is not filed about a specific source package though, rather it is just filed against Ubuntu in general. It is important that bug reports be filed about source packages so that people interested in the package can find the bugs about it. You can find some hints about determining what package your bug might be about at https://wiki.ubuntu.com/Bugs/FindRightPackage. You might also ask for help in the #ubuntu-bugs irc channel on Freenode.

To change the source package that this bug is filed about visit https://bugs.launchpad.net/ubuntu/+bug/1476753/+editstatus and add the package name in the text box next to the word Package.

[This is an automated message. I apologize if it reached you inappropriately; please just reply to this message indicating so.]

[Patrick Lee (patrdck)]

Verified bug against version 1.12.1-0ubuntu4.2 of the upstart source package

[Gerard Weatherby (gweatherby)]

Ran into this, too.