How to debug an upstart script that intermittently fails?

Question

I have a process that I want to start as soon my system is rebooted by whatever means so I was using upstart script for that but sometimes what I am noticing is my process doesn't get started up during hard reboot (plugging off and starting the machine) so I think my upstart script is not getting kicked in after hard reboot. I believe there is no runlevel for Hard Reboot.

I am confuse that why sometimes during reboot it works, but sometimes it doesn't work. And how can I debug this out?

Below is my upstart script:

# sudo start helper
# sudo stop helper
# sudo status helper
start on runlevel [2345]
stop on runlevel [!2345]

chdir /data
respawn

pre-start script
  echo "[`date`] Agent Starting" >> /data/agent.log
  sleep 30
end script

post-stop script
  echo "[`date`] Agent Stopping" >> /data/agent.log
  sleep 30
end script

limit core unlimited unlimited
limit nofile 100000 100000
setuid goldy
exec python helper.py

Is there any way to debug this out what's happening? I can easily reproduce this I believe. Any pointers on what I can do here?

Note:

During reboot sometimes I see the logging that I have in pre-start script but sometimes I don't see the logging at all after reboot and that means my upstart script was not triggered. Is there anything I need to change on runlevel to make it work?

I have a VM which is running in a Hypervisor and I am working with Ubuntu.

Immesh

You might temporarily replace your exec python helper.py with something like: script exec 2>>/path/to/log.txt set -x exec python helper.py end script; that way you have a record in /path/to/log.txt of what happened during startup. – Prostrate

Can you check /var/log/upstart and see if that has something you need? – Ponceau

already checked and there is nothing in that I believe. – Immesh

@david, do you see logs of other services in /var/log/upstart or the log itself is blank. Also run dmesg and see if you can find anything related to your service – Ponceau

Answer 1

Your process running nicely, BUT during system startup many things go parallel.

IF mount (which makes available the /data folder) runs later than your pre-start script you will not see the "results" of pre-start script.

I suggest to move sleep 30 earlier (BTW 30 secs seems too looong):

pre-start script
  sleep 30 # sleep 10 should be enough
  echo "[`date`] Agent Starting" >> /data/agent.log
end script

Put

ok will try this out but is there any other runlevel I can use that will guarantee to run my upstart script after every other upstart scripts has run (like mount)? – Immesh

If you want to be sure your script runs after mount - more specific after local mounts, enter start on local-filesystems - this runs a bit later than start on runlevel [2345] – Put

ok I tried by moving sleep just above and still it doesnt work few of the times so I have to start it manually. But what I have noticed is if I use this start on stopped rc instead of my original start line then it works always as per my testing. Do you know what could be the difference with my new changes? – Immesh

@david, from my /etc/init/rc.conf Upstart config file: " # rc - System V runlevel compatibility # # This task runs the old System V-style rc script when changing between # runlevels. " So your script starts now after all runlevel change script has finished. – Put

So do you think that is helping me out? I am still not able to understand that why after switching to start on stopped rc, it works consistently always after reboot. Do you know why? – Immesh

Any thought on this? – Immesh

Ops. Yes. start on stopped rc means start when all rc script has ended. Means it starts as last (later than old S99* SystemV scripts). Meanwhile I do not understand why sleep <many> does not works - despite of the fact it is clumsy. I assumed problem is solved, as you mentioned... – Put

Maybe it is waiting for something else to start but my upstart script is getting started earlier? – Immesh