Add boot-services milestone marker for boot; fixed udev-addon init time.

Add boot-services milestone marker for boot; fixed udev-addon init time.

This fixes problems where udev-addon could start before udev did if the
system boot was very slow (like on ARM boards today).  Now, we prevent
the failsafe delay and system-services from starting until critical 
boot services (like udev, dbus, and syslog) have finished starting.
Now, services that depend on failsafe can assume that boot-services
are present, which seems like a good idea.

This speficially solves problems where USB Ethernet and Camera 
weren't being properly setup on some ARM-based boards.

BUG=chromium-os:14299
TEST=Several

Test #1: Validate that my ARM device now consistently brings up the network and other peripherals.

--

Test #2: Ran bootperf before and after (x86-generic on a CR-48).  

Before:
(on 10 cycles):
 time  s%     dt  s%  event
 1619  3%  +1619  3%  startup
 1899  2%   +280  4%  startup_done
 3401  9%  +1502 22%  x_started
 3792  5%   +391 57%  chrome_exec
 5004  1%  +1212 14%  chrome_main
 5988  1%   +984  5%  login
11607  1%  +5619  1%  network

After:
(on 10 cycles):
 time  s%     dt  s%  event
 1632  3%  +1632  3%  startup
 1905  3%   +273 10%  startup_done
 3566  8%  +1661 17%  x_started
 3839  5%   +273 54%  chrome_exec
 4956  2%  +1117 19%  chrome_main
 5961  2%  +1005 12%  login
11612  1%  +5651  1%  network

...all differences are within margins...

--

Test #3: Added a bunch of debug code into my startup scripts, then saw:

[   63.789794] chromeos_startu used greatest stack depth: 4868 bytes left
init: nvrm main process (823) terminated with status 113
DOUG: dbus pre-start
DOUG: udev prestart
DOUG: syslog prestart

Developer Console

[ ...cut... ]

DOUG: dbus pre-start end
DOUG: dbus start
[  123.583095] cfg80211: Calling CRDA to update world regulatory domain
[  153.516623] brcmfmac: module is from the staging directory, the quality is unknown, you have been warned.

[ ...cut... ]

[  153.889371] modprobe used greatest stack depth: 4852 bytes left
DOUG: udev prestart end
DOUG: udev start
[  153.922999] udevd (927): /proc/927/oom_adj is deprecated, please use /proc/927/oom_score_adj instead.
DOUG: failsafe delay start
[  167.548024] Firmware version = wl0: Sep  7 2010 10:38:12 version 4.218.248.5
DOUG: boot-complete done
DOUG: udev-addon start
DOUG: iptables start
[  170.580429] Linux video capture interface: v2.00

[ ...cut... ]

[  174.037514] eth1: link up, 100Mbps, full-duplex, lpa 0xCDE1
DOUG: failsafe delay done

--

Test #4: Boot using 'init --verbose' for upstart and look at logs (not included here).

--

Test #5: Ran smoke_Suite.

Committed: http://chrome-svn/viewvc/chromeos?view=rev&revision=e26585f

[diandersAtChromium, 2011-04-19 23:22:49]

Richard,

Does this look like what you were thinking of?  Thanks!  :)

[jrbarnette, 2011-04-20 00:04:39]

One general comment:  The copyright date on all files needs to be
updated to 2011, including for the new file. :-)

http://codereview.chromium.org/6879062/diff/1/boot-services.conf
File boot-services.conf (right):

http://codereview.chromium.org/6879062/diff/1/boot-services.conf#newcode15
boot-services.conf:15: # Tasks that want to wait for all boot services to be
finished should use
s/finished/ready/

http://codereview.chromium.org/6879062/diff/1/boot-services.conf#newcode19
boot-services.conf:19: # TODO(dianders): Should anyone use a 'stop on' for
boot-services?
Yes, the syslog, dbus, and udev jobs should all say this:
  start on starting boot-services
  stop on stopping boot-services

The comment above (line 13) should say so.  You can then delete
the TODO.

http://codereview.chromium.org/6879062/diff/1/boot-services.conf#newcode22
boot-services.conf:22: start on runlevel 2
Add here the standard 'stop on' boilerplate:
  stop on starting halt or starting reboot

http://codereview.chromium.org/6879062/diff/1/system-services.conf
File system-services.conf (right):

http://codereview.chromium.org/6879062/diff/1/system-services.conf#newcode16
system-services.conf:16: # have been started.
A comment like this should be added to the 'failsafe' job as well.

[diandersAtChromium, 2011-04-20 16:10:02]

Thanks for your quick feedback on this.  It is definitely appreciated!  :)

I think I have addressed all review concerns.  I'm planning to run suite_Smoke
against my local Aebl and a few x86 machines.  

I will also do a before/after "boot perf" on this change.

http://codereview.chromium.org/6879062/diff/1/boot-services.conf
File boot-services.conf (right):

http://codereview.chromium.org/6879062/diff/1/boot-services.conf#newcode15
boot-services.conf:15: # Tasks that want to wait for all boot services to be
finished should use
On 2011/04/20 00:04:39, jrbarnette wrote:
> s/finished/ready/

Done.

http://codereview.chromium.org/6879062/diff/1/boot-services.conf#newcode19
boot-services.conf:19: # TODO(dianders): Should anyone use a 'stop on' for
boot-services?
On 2011/04/20 00:04:39, jrbarnette wrote:
> Yes, the syslog, dbus, and udev jobs should all say this:
>   start on starting boot-services
>   stop on stopping boot-services
> 
> The comment above (line 13) should say so.  You can then delete
> the TODO.

Done.

http://codereview.chromium.org/6879062/diff/1/boot-services.conf#newcode22
boot-services.conf:22: start on runlevel 2
On 2011/04/20 00:04:39, jrbarnette wrote:
> Add here the standard 'stop on' boilerplate:
>   stop on starting halt or starting reboot

Done.

http://codereview.chromium.org/6879062/diff/1/system-services.conf
File system-services.conf (right):

http://codereview.chromium.org/6879062/diff/1/system-services.conf#newcode16
system-services.conf:16: # have been started.
On 2011/04/20 00:04:39, jrbarnette wrote:
> A comment like this should be added to the 'failsafe' job as well.

Done.

[diandersAtChromium, 2011-04-20 16:36:44]

NOTE: Two comments about things I'm not sure are right.  I noticed some errors
in the console when trying to restart and think they might be related (?).  Is
it OK if I remove these and go back to the old shutdown behavior, or would you
like me to track further.

Thanks!

http://codereview.chromium.org/6879062/diff/3002/dbus.conf
File dbus.conf (right):

http://codereview.chromium.org/6879062/diff/3002/dbus.conf#newcode11
dbus.conf:11: stop on stopping boot-services
NOTE: I'm not convinced this is right.  It certainly changes behavior.  I am
getting errors spewed when I do a 'shutdown -r now' from the command line.  I
will check whether this was the cause.

http://codereview.chromium.org/6879062/diff/3002/udev.conf
File udev.conf (right):

http://codereview.chromium.org/6879062/diff/3002/udev.conf#newcode12
udev.conf:12: stop on stopping boot-services
NOTE: I'm not convinced this is right.  It certainly changes behavior.  I am
getting errors spewed when I do a 'shutdown -r now' from the command line.  I
will check whether this was the cause.

[jrbarnette, 2011-04-20 16:57:18]

On Apr 20, 2011, at 9:36 AM, dianders@chromium.org wrote:

> NOTE: Two comments about things I'm not sure are right.  I noticed  
> some errors
> in the console when trying to restart and think they might be  
> related (?).  Is
> it OK if I remove these and go back to the old shutdown behavior, or  
> would you
> like me to track further.
>
> Thanks!
>
>
> http://codereview.chromium.org/6879062/diff/3002/dbus.conf
> File dbus.conf (right):
>
> http://codereview.chromium.org/6879062/diff/3002/dbus.conf#newcode11
> dbus.conf:11: stop on stopping boot-services
> NOTE: I'm not convinced this is right.  It certainly changes behavior.
> I am getting errors spewed when I do a 'shutdown -r now' from the
> command line.  I will check whether this was the cause.
>
> http://codereview.chromium.org/6879062/diff/3002/udev.conf
> File udev.conf (right):
>
> http://codereview.chromium.org/6879062/diff/3002/udev.conf#newcode12
> udev.conf:12: stop on stopping boot-services
> NOTE: I'm not convinced this is right.  It certainly changes behavior.
> I am getting errors spewed when I do a 'shutdown -r now' from the
> command line.  I will check whether this was the cause.
>
I would expect that the new errors are caused by the change.
Could you send the text of the messages?  I'd like to gauge
the real root cause and the severity of the issue.

Thanks!


> http://codereview.chromium.org/6879062/

-- jrb

[diandersAtChromium, 2011-04-20 17:04:53]

...confirmed: commenting out the two 'stop on' clauses that were added prevents
the errors.  

They are hard to write down since they fly by really fast (and I don't think
make it into any logs?).  ...but a quick video recording w/ my phone solved the
problem!  :)  In at least one case, it said:

init: wpasupplicant main process ended, respawning
init: wpasupplicant main process (...) terminated with status 255
init: wpasupplicant main process ended, respawning
init: wpasupplicant main process (...) terminated with status 255
init: wpasupplicant main process ended, respawning
init: wpasupplicant main process (...) terminated with status 255

I think previously I saw similar errors w/ flimflam.  I will see if I can
reproduce.

[diandersAtChromium, 2011-04-20 17:11:16]

Don't see the flimflam one, but to be complete, I see the following before the
wpasupplicant errors:

init: powerd main process (...) killed by TERM signal
init: dbus main process (...) killed by TERM signal
init: wpasupplicant main process (...) terminated with status 1
init: wpasupplicant main process ended, respawning

...

[jrbarnette, 2011-04-20 17:31:47]

On 2011/04/20 17:11:16, diandersAtChromium wrote:
> Don't see the flimflam one, but to be complete, I see the following before the
> wpasupplicant errors:
> 
> init: powerd main process (...) killed by TERM signal
> init: dbus main process (...) killed by TERM signal
> init: wpasupplicant main process (...) terminated with status 1
> init: wpasupplicant main process ended, respawning
> 
> ...

OK.  I believe this means that the change to the 'stop on'
stanza changed the ordering of shutdown operations.  I
don't know why, and I'm not inclined to investigate (*yet*).

You should feel free to drop the 'stop on' change.

[diandersAtChromium, 2011-04-20 17:57:06]

PTAL.  

smoke_Suite is still pending, but bootperf test finished (I ran it with patch
set #2, but I think that's OK).  Will wait for smoke_Suite w/ patch set #3 to
pass before I push.

Thanks!

[diandersAtChromium, 2011-04-20 18:31:34]

Here are smoke test results (x86-generic on Cr-48).  

I think we're good.  ...just looking for LGTM now.  ;)  Thanks again for all
your help on this one.

---

INFO    : Test results:
----------------------------------------------------
suite_Smoke                                    PASS
suite_Smoke/build_RootFilesystemSize           PASS
  bytes_rootfs_prod                            549810176.0
  bytes_rootfs_test                            549908480.0
suite_Smoke/desktopui_ChromeFirstRender        PASS
  seconds_chrome_first_tab                     1.96
suite_Smoke/desktopui_FlashSanityCheck         PASS
suite_Smoke/desktopui_KillRestart.chrome       PASS
suite_Smoke/desktopui_KillRestart.session      PASS
suite_Smoke/logging_CrashSender                PASS
suite_Smoke/logging_UserCrash                  PASS
suite_Smoke/login_BadAuthentication            PASS
suite_Smoke/login_CryptohomeIncognitoMounted   PASS
suite_Smoke/login_CryptohomeIncognitoUnmounted PASS
suite_Smoke/login_CryptohomeMounted            PASS
suite_Smoke/login_CryptohomeUnmounted          PASS
suite_Smoke/login_LoginSuccess.apps            PASS
suite_Smoke/login_LoginSuccess.default         PASS
suite_Smoke/login_OwnershipNotRetaken          PASS
suite_Smoke/login_OwnershipTaken               PASS
suite_Smoke/platform_FilePerms                 PASS
suite_Smoke/platform_OSLimits                  PASS
----------------------------------------------------
Total PASS: 19/19 (100%)

No crashes detected during testing.
Elapsed time: 5m57s

[jrbarnette, 2011-04-20 18:49:46]

On 2011/04/20 18:31:34, diandersAtChromium wrote:
> Here are smoke test results (x86-generic on Cr-48).  
> 
> I think we're good.  ...just looking for LGTM now.  ;)  Thanks again for all
> your help on this one.
> 
LGTM!

Thanks!


> ---
> 
> INFO    : Test results:
> ----------------------------------------------------
> suite_Smoke                                    PASS
> suite_Smoke/build_RootFilesystemSize           PASS
>   bytes_rootfs_prod                            549810176.0
>   bytes_rootfs_test                            549908480.0
> suite_Smoke/desktopui_ChromeFirstRender        PASS
>   seconds_chrome_first_tab                     1.96
> suite_Smoke/desktopui_FlashSanityCheck         PASS
> suite_Smoke/desktopui_KillRestart.chrome       PASS
> suite_Smoke/desktopui_KillRestart.session      PASS
> suite_Smoke/logging_CrashSender                PASS
> suite_Smoke/logging_UserCrash                  PASS
> suite_Smoke/login_BadAuthentication            PASS
> suite_Smoke/login_CryptohomeIncognitoMounted   PASS
> suite_Smoke/login_CryptohomeIncognitoUnmounted PASS
> suite_Smoke/login_CryptohomeMounted            PASS
> suite_Smoke/login_CryptohomeUnmounted          PASS
> suite_Smoke/login_LoginSuccess.apps            PASS
> suite_Smoke/login_LoginSuccess.default         PASS
> suite_Smoke/login_OwnershipNotRetaken          PASS
> suite_Smoke/login_OwnershipTaken               PASS
> suite_Smoke/platform_FilePerms                 PASS
> suite_Smoke/platform_OSLimits                  PASS
> ----------------------------------------------------
> Total PASS: 19/19 (100%)
> 
> No crashes detected during testing.
> Elapsed time: 5m57s