Is the boot time on other platforms mostly unaffected?

I made some experiments on Kevin to get a better understanding which part(s) of udev are causing the delay. Starting point is a R57-9170 image with udev-208 and log entries in /etc/init/udev-trigger*.conf. Successive updates of different udev components indicate that most of the delta comes from the udev daemon, and not from libudev (which underwent significant changes in event handling) or udevadm:

# udevd-208, libudev-208, udevadm-208
[    1.156036] MKA: trigger (early)
[    1.281745] MKA: done
[    1.281872] MKA: settle (early)
[    1.531865] MKA: done
[    1.639973] MKA: trigger (codec)
[    1.852582] MKA: done
[    1.852611] MKA: settle (codec)
[    2.305927] MKA: done
[    8.810535] MKA: udevadm settle
[    9.378248] MKA: done

# udevd-208, libudev-225, udevadm-208
[    1.150980] MKA: trigger (early)
[    1.238035] MKA: done
[    1.238087] MKA: settle (early)
[    1.606498] MKA: done
[    1.723251] MKA: trigger (codec)
[    2.008128] MKA: done
[    2.008157] MKA: settle (codec)
[    2.306604] MKA: done
[    9.031762] MKA: udevadm settle
[    9.842263] MKA: done

# udevd-208, libudev-225, udevadm-225
[    1.145918] MKA: trigger (early)
[    1.395678] MKA: done
[    1.395707] MKA: settle (early)
[    1.400995] MKA: done
[    1.662464] MKA: trigger (codec)
[    3.312696] MKA: done
[    3.312725] MKA: settle (codec)
[    3.317375] MKA: done
[    9.897032] MKA: udevadm settle
[   10.087927] MKA: done

# udevd-225, libudev-225, udevadm-225
[    1.181435] MKA: trigger (early)
[    1.562641] MKA: done
[    1.562672] MKA: settle (early)
[    2.660977] MKA: done
[    2.857646] MKA: trigger (codec)
[    4.738647] MKA: done
[    4.738676] MKA: settle (codec)
[    4.743341] MKA: done
[   11.332802] MKA: udevadm settle
[   14.841540] MKA: done

the weird thing is that the bootchart shows udevadm using cpu vs just being idle and waiting for udev itself

The high CPU load of udevadm is indeed odd. From my observations 'udevadm settle' should sleep most of the time, unless poll() on the event queue descriptor involves significantly more activity that I'd expect.

cywang@, are there instructions on how to generate/enable these boot charts? Generating them on my system might be helpful for further debugging.

One thing I miss in the 9178 chart is lmt-udev (laptop-mode udev handlers). I verified that the handlers are executed on my build with udev-208. 

Here are the steps to generate bootchart:

cros deploy DUT_IP bootchart
reboot DUT
Stop bootchart service(not necessary as it will stop in 10 seconds automatically)
Copy the boot*.tgz under /var/log/bootchart/ back to your workstation
Use pybootchartgui on your workstation to generate bootchart.png

Thanks cywang@!

Mark it as P1 for M57 as it is around 2+ seconds boot time regression.

The worst regression is on lumpy
https://chromeperf.appspot.com/report?sid=12bfe5e6b6aa043276ead021b0d53d4b86da167498f98f6b2e5f49792f277789&rev=29800000918600000

There are different factors that contribute to the delay:

1)

About 2s stem from the various "udevadm trigger" runs in /etc/init/udev-trigger*.conf (https://chromium.googlesource.com/chromiumos/platform2/+/release-R57-9202.B/init/).

The command reads and parses ${dev}/uevent for each ${dev} that matches the filter specified in the parameters. This is not the case with udevadm-208. This wouldn't be necessarily a problem if the filters were relatively narrow, however the opposite is true for the filters on CrOS. In many cases the only filter is the content of a sysfs attribute, in consequence virtually all devices need to be processed. This can be mitigated with narrower rules, e.g. by adding a filter for the subystem or bus.

Further there are many platform specific invocations of "udevadm trigger". Ideally the command would only run if it is needed for the platform in question.

2)

Related with 1): Reading the ${dev}/uevent of the sbs-9 battery takes 80+ ms, which adds up if done multiple times. I haven't instrumented the driver code yet, but I suspect that the delays are caused by reading reading a bunch of values via I2C when ${dev}/uevent is read.

3)

In my observations on kevin "udevadm settle" from /etc/init/udev-trigger.conf returns almost intermediately with udev-208, with udev-225 it exits after all USB devices have been initialized, which typically occurs after a few seconds.

I'm not entirely sure, what the behavior should be. According to a comment in the .conf file "system-services requires udev event processing to be completed before it emits started". udevadm-208 returns before the processing of some USB devices is complete, however one could also argue that udev event processing is never completed since new devices can be added at any time. 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/1c4406cc99c3b54890af79946c10be602f839238

commit 1c4406cc99c3b54890af79946c10be602f839238
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Wed Jan 25 23:41:06 2017

init: Use more specific filters for early udev triggers

Filtering only on the device name forces udevadm to examine virtually
all devices. This has become more expensive with newer udev versions.
Limit the devices to be examined to the subsystem they belong to.

BUG= chromium:682578 
TEST=build and boot on kevin
  run udevadm monitor in one console
  run changed commands in other console
  verify udevadm monitor receives 'add' events for both commands

Change-Id: Id75882e4f38dfc94911a792ecd31b1b880152881
Reviewed-on: https://chromium-review.googlesource.com/433163
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>

[modify] https://crrev.com/1c4406cc99c3b54890af79946c10be602f839238/init/udev-trigger-early.conf

More info on 3):

At least on kevin 'udevadm settle' waits for laptop-mode udev handlers to finish. With a hacked /lib/udev/lmt-udev that does nothing 'udevadm settle' exits almost immediately.

So 'udevadm-225 settle' does what it is asked for, even though this results in an increased boot time.

Not sure what the short term solution would be, assuming that it is necessary to wait for uevent processing to be finished, as the comment suggests. Longer term it is planned to replace laptop-mode-tools, this would probably resolve the LMT delay, though some platforms might have other longer running (non-LMT) udev handlers. Initially the upgrade to udev-225 was mainly motivated by fixing a problem with Gnubby, which is probably less critical than the boot delay. This might suggest rolling back to udev-208, however I heard that ARC++ was also pending on the udev upgrade, because it fixes issues they observed with udev-208.

In the discussion about the LMT replacement one idea was to replace the LMT autosuspend module with a set of udev rules. This should be relatively easy to implement and disabling autosuspend in LMT should reduce its runtime significantly. While the udev handlers would still have to run similar code to enable autosuspend, they could run in parallel, instead of contending for the LMT lock.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/f769af097252e78eb73202bb319162df28af7356

commit f769af097252e78eb73202bb319162df28af7356
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Thu Jan 26 18:18:55 2017

media-rules: Use more specific filters for codec udev triggers

Filtering only on the device name forces udevadm to examine virtually
all devices. This has become more expensive with newer udev versions.
Limit the devices to be examined to the subsystem they belong to.

Further most of the devices used here are specific to certain SoC
platforms. Only run udevadm trigger on platforms where the device can
be expected.

BUG= chromium:682578 
TEST=manual

Change-Id: I5273c9ec199f8e3ffbfe84a4ed886d3785d3c995
Reviewed-on: https://chromium-review.googlesource.com/433837
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Matthias Kaehlcke <mka@chromium.org>

[rename] https://crrev.com/f769af097252e78eb73202bb319162df28af7356/media-libs/media-rules/media-rules-0.1.0-r11.ebuild
[modify] https://crrev.com/f769af097252e78eb73202bb319162df28af7356/media-libs/media-rules/files/udev-trigger-codec.conf

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/2edd5d8f29ea49855e5c5118eda60e4439e66e77

commit 2edd5d8f29ea49855e5c5118eda60e4439e66e77
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Fri Jan 27 17:38:50 2017

init: Add platform subsystem to early udev trigger for EC devices

Some EC devices are part of the platform subystem.

BUG= chromium:682578 
TEST=boot on veyron
  run udevadm monitor in one console
  run changed command in other console
  verify udevadm monitor receives 'add' events for both 'platform' and 'chromeos' devices

Change-Id: Iae8f680b74964fb30b5ca3095bad5406e6ada6a0
Reviewed-on: https://chromium-review.googlesource.com/433452
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Gwendal Grignou <gwendal@chromium.org>

[modify] https://crrev.com/2edd5d8f29ea49855e5c5118eda60e4439e66e77/init/udev-trigger-early.conf

From https://cros-goldeneye.corp.google.com/chromeos/console/listCrosbolt it seems the above changes are helping on some platforms:

kevin: back to 9178 boot time
elm: close to 9178 boot time

veyron: too noisy to tell, other factors might have increased boot time further
blaze: no visible impact

lumpy: no data available on the dashboard

Another bunch of CLs have been submitted which take autosuspend and runtime PM out of LMT and configure it through udev handlers as mentioned in #12 ( Issue 686168 ). We will see in the next days on the perf dashboard if this helps to further improve boot time.

FYI (since it seems to be tagged for M-57) CL:433837 broke HW video decode on RK3399 on R58. The problem is tracked in http://crbug.com/p/62563 and fixed by CL:435122. Care needs to be taken when merging.

Aha, found Matthias' fix (CL:435648). Updated the commit message a bit.

Next time please let people responsible for given area know that there is a problem and fix - in this case filing a bug for Cr-OS-Kernel-Video or at least adding posciak@ as reviewer could have saved us some time debugging this.

tfiga@: Sorry for not notifying, I noticed the error while looking at something else and hadn't seen any symptoms of an actual problem.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/3c2aae94783071faf23abf263726cf3d5e90a376

commit 3c2aae94783071faf23abf263726cf3d5e90a376
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Thu Feb 02 20:33:14 2017

media-rules: Fix subsystem name for rk3399 triggers

In CL:433837 we changed the udev-trigger-codec.conf script to only
trigger the events meaningful for the platform the script is run on, but
rk3399 triggers were mistakenly changed to match using --subsystem-match
with "platform", instead of "video4linux", which was incorrect and could
not match devices in question.

Fix the script by making it use the correct subsystem match.

BUG= chromium:682578 
BUG=chrome-os-partner:62563
TEST=install on kevin|gru
  open two terminals on DUT
  term 1: udevadm monitor
  term 2: execute changed commands
  expected result: udevadm monitor reports a video4linux uevent for
    each command

Change-Id: I0dd2b2f0dd96a212392d6077b4c07730d2717577
Reviewed-on: https://chromium-review.googlesource.com/435648
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Tomasz Figa <tfiga@chromium.org>
Reviewed-by: Pawel Osciak <posciak@chromium.org>

[rename] https://crrev.com/3c2aae94783071faf23abf263726cf3d5e90a376/media-libs/media-rules/media-rules-0.1.0-r12.ebuild
[modify] https://crrev.com/3c2aae94783071faf23abf263726cf3d5e90a376/media-libs/media-rules/files/udev-trigger-codec.conf

I got my hands on a veyron mighty, the changes apparently had the desired effect, in my observations udev-trigger with udev-225 finishes now at the same time or earlier than with udev-208:

# 9176 (udev-208)

# best
[   11.065613] MKA: settle
[   11.437267] MKA: done


# worst
[   10.941427] MKA: settle
[   12.538972] MKA: done


# 9247 (udev-225)

# best
[    9.319999] MKA: settle
[   10.884917] MKA: done

# worst
[   10.319618] MKA: settle
[   11.414679] MKA: done

cywang@: Do you know what exactly is measured in "Time to Login"?

As mentioned in the previous comment on veyron_mighty the udev-trigger task now exits roughly at the same time or earlier than with udev-208, however according to the performance dashboard there is no improvement in the metric:

https://cros-goldeneye.corp.google.com/chromeos/console/listCrosbolt?baselineMilestoneChannel=57%20%3A%20DEV&comparisonMilestoneChannel=58%20%3A%20DEV&analysisType=BUILD_TO_BUILD&selectedDevices=blaze_cpu_nyan_2Gb%2Celm_cpu_mtk_4core_18g_4Gb%2Ckevin_rk3399_4Gb%2Cmighty_rk3288_2Gb

The metric 'Time to login' is the value of 'seconds_power_on_to_login' in platform_BootPerf test. Actually it is the time 'seconds_power_on_to_kernel' + 'seconds_kernel_to_login' - for example - https://chromeperf.appspot.com/report?sid=d04977ff6ceaaf47480e8ba04309246201e7abb31bfed8ac6782286bce73448a

'seconds_power_on_to_kernel' is mainly the elapsed time from power_on to bootloader/firmware part before kernel got loaded.

'seconds_kernel_to_login' includes the time from kernel to all init jobs until the Chrome emits the 'login-prompt-visible' -> boot-complete -> report-boot-complete(i.e. the timestamp of the bootstat recorded in /tmp/uptime-boot-complete).

You could take a look at the test platform_BootPerf for more details - https://chromium.googlesource.com/chromiumos/third_party/autotest/+/master/client/site_tests/platform_BootPerf/platform_BootPerf.py

I don't think udev uprev is the culprit now from what we could see - https://chromeperf.appspot.com/report?sid=89c5e28d1238ff0b6cfb95778ea5669e875e1c19e010554cad2c27fd869f7149, the 'seconds_kernel_to_chrome_exec'(i.e. timestamp for launching chrome exectuable) was dropped since build R58-9225.0.0. However, the initialization part inside Chrome is taking more and more time. If we are sure there is no other udev regression on other platforms, should be okay to close this bug. Thanks!

@24: is this link supposed to work? It doesn't for me...

Forgot to mention that you have to login('sign in') the chromeperf site in order to see the results.

In case you are still not able to see the graph.

Deleted: veyron_mighty.png 188 KB

	veyron_mighty.png 188 KB View Download

cywang@: Thanks for the details and for pointing out that Chrome initialization is now causing the delay.

The delay on Lumpy still needs to be fixed before closing the bug. I root caused it, the review of the fix is pending.

Slow boot times (20+ seconds) are being reported by multiple users on CBC

https://productforums.google.com/forum/#!topic/chromebook-central/q0I-Rp53t6o;context-place=forum/chromebook-central

#CBC-RS/TC-watchlist

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/b16a9d738b08ef2644ec333ad17510928d3ee91c

commit b16a9d738b08ef2644ec333ad17510928d3ee91c
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Fri Feb 10 20:11:45 2017

media-rules: Make udev rules more specific

The udev rules matched only the attribute name, which forces udev to
check the attribute of completely unrelated devices (e.g. block, power,
...) and for any type of event (e.g. changes in battery level). Only
execute the rules when a new device is added to the video4linux subsystem.

BUG= chromium:682578 
TEST=install on kevin|gru
  verify /dev has symlinks video-dec, video-dec0, video-dec1 and video-enc

Change-Id: I3289222af54e21e4b50ddd439f801c39ca0c9ee3
Reviewed-on: https://chromium-review.googlesource.com/435649
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Owen Lin <owenlin@chromium.org>

[modify] https://crrev.com/b16a9d738b08ef2644ec333ad17510928d3ee91c/media-libs/media-rules/files/50-media.rules
[rename] https://crrev.com/b16a9d738b08ef2644ec333ad17510928d3ee91c/media-libs/media-rules/media-rules-0.1.0-r13.ebuild

the boot regression is in M56 & M57.  so far we're only landing on ToT, and we'll prob cherry pick back stuff to M57, but i think we missed the boat on M56.  that'll be up to the PMs i think.

#31: The udev upgrade is not part of M56, the problems there must have a different cause. 

sorry, you're right.  when i looked at the git log, i confused the commit "add (masked)" with the "unmask" one on M57.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/d5fcb0af394dba6d04d4e324ee977250d3b7298e

commit d5fcb0af394dba6d04d4e324ee977250d3b7298e
Author: Takashi Iwai <tiwai@suse.de>
Date: Sat Feb 11 06:37:32 2017

UPSTREAM: firmware: Refactoring for splitting user-mode helper code

Since 3.7 kernel, the firmware loader can read the firmware files
directly, and the traditional user-mode helper is invoked only as a
fallback.  This seems working pretty well, and the next step would be
to reduce the redundant user-mode helper stuff in future.

This patch is a preparation for that: refactor the code for splitting
user-mode helper stuff more easily.  No functional change.

BUG= chromium:682578 
TEST=build and and boot on lumpy
  dmesg | grep "Cannot load firmware"
    => no result (hda-intel would print this trace in case of error)

cherry picked from commit 4e0c92d01523 ("firmware: Refactoring for
splitting user-mode helper code")

Acked-by: Ming Lei <ming.lei@canonical.com>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Change-Id: Id774bed9f91414df298c9c27c4a516c0259b13b2
Reviewed-on: https://chromium-review.googlesource.com/438681
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Brian Norris <briannorris@chromium.org>

[modify] https://crrev.com/d5fcb0af394dba6d04d4e324ee977250d3b7298e/drivers/base/firmware_class.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/105dd54e6aa087750ca7002e94efb46e6d394289

commit 105dd54e6aa087750ca7002e94efb46e6d394289
Author: Takashi Iwai <tiwai@suse.de>
Date: Sat Feb 11 06:37:33 2017

UPSTREAM: firmware: Make user-mode helper optional

This patch adds a new kconfig, CONFIG_FW_LOADER_USER_HELPER, and
guards the user-helper codes in firmware_class.c with ifdefs.

Yeah, yeah, there are lots of ifdefs in this patch.  The further
clean-up with code shuffling follows in the next.

BUG= chromium:682578 
TEST=build w/ CONFIG_FW_LOADER_USER_HELPER=y and boot lumpy
  dmesg | grep "Cannot load firmware"
    => no result (hda-intel would print this trace in case of error)

  build w/ CONFIG_FW_LOADER_USER_HELPER not set and boot lumpy
  dmesg | grep "Cannot load firmware"
    => no result
  dmesg | grep "r8169.*link"
    => timestamp < 15s (indicates user helper was actually skipped for
        for r8169 Ethernet interface)

cherry picked from commit 7b1269f77878 ("firmware: Make user-mode
helper optional")

Acked-by: Ming Lei <ming.lei@canonical.com>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Change-Id: I914bb6583e37cd7aa2ed89d6886c244f917d66e2
Reviewed-on: https://chromium-review.googlesource.com/438682
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Brian Norris <briannorris@chromium.org>

[modify] https://crrev.com/105dd54e6aa087750ca7002e94efb46e6d394289/drivers/base/Kconfig
[modify] https://crrev.com/105dd54e6aa087750ca7002e94efb46e6d394289/drivers/base/firmware_class.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/d08e5142f0a2519397723bfccd7e4f55b3d86eb9

commit d08e5142f0a2519397723bfccd7e4f55b3d86eb9
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Sat Feb 11 06:37:34 2017

CHROMIUM: config: Disable firmware userspace helper

CrOS recently updated to udev-225, which removed userspace firmware
loading support. The r8169 driver tries to load the firmware, however
CrOS images don't ship with r8169 firmware. When the in-kernel firmware
loading fails the driver falls back to the user-helper, which results in
a boot delay of ~60s (observed on lumpy). Disable the userspace helper
to fail faster.

BUG= chromium:682578 
TEST=build and and install on lumpy
  connect network cable to Ethernet port
  boot lumpy (without USB to Ethernet adapter)
  wait 10s
  ifconfig eth0
    => eth0 got an IP address

Signed-off-by: Matthias Kaehlcke <mka@chromium.org>

Change-Id: I570c5fe86d7902eb2441d7fd4366072c3a304858
Reviewed-on: https://chromium-review.googlesource.com/438830
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Brian Norris <briannorris@chromium.org>

[modify] https://crrev.com/d08e5142f0a2519397723bfccd7e4f55b3d86eb9/chromeos/config/base.config

 Issue 682034  has been merged into this issue.

 Issue 688560  has been merged into this issue.

This also makes it impossible to lock the screen in some cases, as discussed in  issue 688560 , so I'm adding ReleaseBlock-Beta.

Your change meets the bar and is auto-approved for M57. Please go ahead and merge the CL to branch 2987 manually. Please contact milestone owner if you have questions.
Owners: amineer@(clank), cmasso@(bling), ketakid@(cros), govind@(desktop)

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/c2e86752e9242dd3af7fb1b77afc57ae3ce93958

commit c2e86752e9242dd3af7fb1b77afc57ae3ce93958
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Tue Feb 14 19:23:31 2017

power: Add script to generate udev rules for autosuspend

The script is part of the effort to replace laptop-mode-tools (LMT). It
generates udev rules to enable/disable autosuspend for certain devices.

The device list is derived from the CrOS configuration file for USB
autosuspend of LMT.

BUG= chromium:214886 ,  chromium:686168 ,  chromium:682578 
TEST=see CL:434906

Change-Id: Ie36a4d1b348f64a029b2657f8e118573c61247e1
Previous-Reviewed-on: https://chromium-review.googlesource.com/435618
(cherry picked from commit 0002ecb756a755ea87f16bb112bf4b0ab58b14a0)
Reviewed-on: https://chromium-review.googlesource.com/442725
Reviewed-by: Dan Erat <derat@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[add] https://crrev.com/c2e86752e9242dd3af7fb1b77afc57ae3ce93958/power_manager/udev/gen_autosuspend_rules.py

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/eb036cafcc0b6bca638352de876d9053a4f8c4ee

commit eb036cafcc0b6bca638352de876d9053a4f8c4ee
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Tue Feb 14 19:23:32 2017

power_manager: Install udev rules to enable device autosuspend

The udev rules substitute the laptop-mode-tools modules USB autosuspend
and runtime PM.

BUG= chromium:214886 ,  chromium:686168 ,  chromium:682578 
CQ-DEPEND=CL:435618, CL:434907
TEST=install on device with 'cyapa' (e.g. daisy_skate)
  disable USB autosuspend and runtime PM in laptop-mode-tools (see next CL)
  insert security key
  cat /sys/bus/usb/devices/${dev}/power/control
    => auto
  insert USB mass storage device
  cat /sys/bus/usb/devices/${dev}/power/control
    => on
  cd /sys
  find -name name -exec grep -H cyapa {} \;
  cat ${dev}/power/control
    => on
  cat ${other_i2c_dev}/power/control
    => auto

Change-Id: If2659288f12369e6d467e2f9d2b3a57a267f9d9f
Previous-Reviewed-on: https://chromium-review.googlesource.com/434906
(cherry picked from commit 0b0731ea17da60c763776d32e9f286237b0d45de)
Reviewed-on: https://chromium-review.googlesource.com/442744
Reviewed-by: Dan Erat <derat@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[modify] https://crrev.com/eb036cafcc0b6bca638352de876d9053a4f8c4ee/chromeos-base/power_manager/power_manager-9999.ebuild

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/7d9800b997addf053dec6aa3092b16680283d269

commit 7d9800b997addf053dec6aa3092b16680283d269
Author: Takashi Iwai <tiwai@suse.de>
Date: Tue Feb 14 19:30:18 2017

UPSTREAM: firmware: Refactoring for splitting user-mode helper code

Since 3.7 kernel, the firmware loader can read the firmware files
directly, and the traditional user-mode helper is invoked only as a
fallback.  This seems working pretty well, and the next step would be
to reduce the redundant user-mode helper stuff in future.

This patch is a preparation for that: refactor the code for splitting
user-mode helper stuff more easily.  No functional change.

BUG= chromium:682578 
TEST=build and and boot on lumpy
  dmesg | grep "Cannot load firmware"
    => no result (hda-intel would print this trace in case of error)

cherry picked from commit 4e0c92d01523 ("firmware: Refactoring for
splitting user-mode helper code")

Acked-by: Ming Lei <ming.lei@canonical.com>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Change-Id: Id774bed9f91414df298c9c27c4a516c0259b13b2
Previous-Reviewed-on: https://chromium-review.googlesource.com/438681
(cherry picked from commit 26dadea46beaaec5116b43780b70976b8d22abd7)
Reviewed-on: https://chromium-review.googlesource.com/442624
Reviewed-by: Guenter Roeck <groeck@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[modify] https://crrev.com/7d9800b997addf053dec6aa3092b16680283d269/drivers/base/firmware_class.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/92645efb7f0ba972d56ee5862e39fccc94d05866

commit 92645efb7f0ba972d56ee5862e39fccc94d05866
Author: Takashi Iwai <tiwai@suse.de>
Date: Tue Feb 14 19:30:24 2017

UPSTREAM: firmware: Make user-mode helper optional

This patch adds a new kconfig, CONFIG_FW_LOADER_USER_HELPER, and
guards the user-helper codes in firmware_class.c with ifdefs.

Yeah, yeah, there are lots of ifdefs in this patch.  The further
clean-up with code shuffling follows in the next.

BUG= chromium:682578 
TEST=build w/ CONFIG_FW_LOADER_USER_HELPER=y and boot lumpy
  dmesg | grep "Cannot load firmware"
    => no result (hda-intel would print this trace in case of error)

  build w/ CONFIG_FW_LOADER_USER_HELPER not set and boot lumpy
  dmesg | grep "Cannot load firmware"
    => no result
  dmesg | grep "r8169.*link"
    => timestamp < 15s (indicates user helper was actually skipped for
        for r8169 Ethernet interface)

cherry picked from commit 7b1269f77878 ("firmware: Make user-mode
helper optional")

Acked-by: Ming Lei <ming.lei@canonical.com>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Change-Id: I914bb6583e37cd7aa2ed89d6886c244f917d66e2
Previous-Reviewed-on: https://chromium-review.googlesource.com/438682
(cherry picked from commit 2c219310f8acaf042f1b1df4b43b51117c4fb874)
Reviewed-on: https://chromium-review.googlesource.com/442644
Reviewed-by: Guenter Roeck <groeck@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[modify] https://crrev.com/92645efb7f0ba972d56ee5862e39fccc94d05866/drivers/base/Kconfig
[modify] https://crrev.com/92645efb7f0ba972d56ee5862e39fccc94d05866/drivers/base/firmware_class.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/60692a9f652d9ffe1b6cd6f0304001337dcb83e1

commit 60692a9f652d9ffe1b6cd6f0304001337dcb83e1
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Tue Feb 14 19:30:29 2017

CHROMIUM: config: Disable firmware userspace helper

CrOS recently updated to udev-225, which removed userspace firmware
loading support. The r8169 driver tries to load the firmware, however
CrOS images don't ship with r8169 firmware. When the in-kernel firmware
loading fails the driver falls back to the user-helper, which results in
a boot delay of ~60s (observed on lumpy). Disable the userspace helper
to fail faster.

BUG= chromium:682578 
TEST=build and and install on lumpy
  connect network cable to Ethernet port
  boot lumpy (without USB to Ethernet adapter)
  wait 10s
  ifconfig eth0
    => eth0 got an IP address

Signed-off-by: Matthias Kaehlcke <mka@chromium.org>

Change-Id: I570c5fe86d7902eb2441d7fd4366072c3a304858
Previous-Reviewed-on: https://chromium-review.googlesource.com/438830
(cherry picked from commit 6761559ccf3ce63592a6cec2e0f855d7d80e077e)
Reviewed-on: https://chromium-review.googlesource.com/442664
Reviewed-by: Guenter Roeck <groeck@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[modify] https://crrev.com/60692a9f652d9ffe1b6cd6f0304001337dcb83e1/chromeos/config/base.config

 Issue 691676  has been merged into this issue.

 Issue 688224  has been merged into this issue.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/1a4351f805957bf5639e70bfde3300019b35f6aa

commit 1a4351f805957bf5639e70bfde3300019b35f6aa
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Wed Feb 15 01:27:44 2017

media-rules: Use more specific filters for codec udev triggers

Filtering only on the device name forces udevadm to examine virtually
all devices. This has become more expensive with newer udev versions.
Limit the devices to be examined to the subsystem they belong to.

Further most of the devices used here are specific to certain SoC
platforms. Only run udevadm trigger on platforms where the device can
be expected.

BUG= chromium:682578 
TEST=manual

Change-Id: I5273c9ec199f8e3ffbfe84a4ed886d3785d3c995
Previous-Reviewed-on: https://chromium-review.googlesource.com/433837
(cherry picked from commit a6e70051eb717bee455e0aa1be5e8226a6b5f032)
Reviewed-on: https://chromium-review.googlesource.com/442075
Reviewed-by: Owen Lin <owenlin@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[rename] https://crrev.com/1a4351f805957bf5639e70bfde3300019b35f6aa/media-libs/media-rules/media-rules-0.1.0-r11.ebuild
[modify] https://crrev.com/1a4351f805957bf5639e70bfde3300019b35f6aa/media-libs/media-rules/files/udev-trigger-codec.conf

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/4905c053eb6136c6b691edbf6758487587180f3d

commit 4905c053eb6136c6b691edbf6758487587180f3d
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Wed Feb 15 01:27:49 2017

media-rules: Fix subsystem name for rk3399 triggers

In CL:433837 we changed the udev-trigger-codec.conf script to only
trigger the events meaningful for the platform the script is run on, but
rk3399 triggers were mistakenly changed to match using --subsystem-match
with "platform", instead of "video4linux", which was incorrect and could
not match devices in question.

Fix the script by making it use the correct subsystem match.

BUG= chromium:682578 
BUG=chrome-os-partner:62563
TEST=install on kevin|gru
  open two terminals on DUT
  term 1: udevadm monitor
  term 2: execute changed commands
  expected result: udevadm monitor reports a video4linux uevent for
    each command

Change-Id: I0dd2b2f0dd96a212392d6077b4c07730d2717577
Previous-Reviewed-on: https://chromium-review.googlesource.com/435648
(cherry picked from commit 2c7346531650961478474320cf52e92695f7ffdd)
Reviewed-on: https://chromium-review.googlesource.com/442097
Reviewed-by: Owen Lin <owenlin@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[rename] https://crrev.com/4905c053eb6136c6b691edbf6758487587180f3d/media-libs/media-rules/media-rules-0.1.0-r12.ebuild
[modify] https://crrev.com/4905c053eb6136c6b691edbf6758487587180f3d/media-libs/media-rules/files/udev-trigger-codec.conf

Another flakiness on wizpig now(Attached) - https://paste.googleplex.com/6228889282019328 , not sure why the usb 1-5 is problematic and it is hammering the boot up time.

2017-02-12T08:20:53.900036-08:00 INFO kernel: [    2.384477] EXT4-fs (mmcblk0p1): re-mounted. Opts: commit=600,data=ordered
2017-02-12T08:20:53.900040-08:00 ERR kernel: [   17.301895] usb 1-5: device descriptor read/64, error -110
2017-02-12T08:20:53.900043-08:00 ERR kernel: [   32.557856] usb 1-5: device descriptor read/64, error -110
2017-02-12T08:20:53.900045-08:00 INFO kernel: [   32.813352] usb 1-5: new full-speed USB device number 6 using xhci_hcd
2017-02-12T08:20:53.900048-08:00 ERR kernel: [   47.968339] usb 1-5: device descriptor read/64, error -110
2017-02-12T08:20:53.900050-08:00 WARNING kernel: [   62.636710] udevd[124]: seq 936 '/devices/pci0000:00/0000:00:14.0/usb1/1-4/1-4:1.0' is taking a long time
2017-02-12T08:20:53.900058-08:00 WARNING kernel: [   62.636961] udevd[124]: seq 937 '/devices/pci0000:00/0000:00:14.0/usb1/1-4/1-4:1.1' is taking a long time

(You could check the original /var/log/message from 
https://storage.cloud.google.com/chromeos-autotest-results/100842618-haddowk/chromeos6-row2-rack20-host17/platform_BootPerfServer.tgz?_ga=1.179927139.653679861.1478837032)

Deleted: wizpig.png 176 KB

	wizpig.png 176 KB View Download

#53:

I'm not convinced that this is an udev issue. The earlier kernel messages suggest a problem with USB. Also the udev upgrade was merged on 01/12/17, however the issue first manifested a month later.

I would suggest to create a separate bug for this.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/0d6b4a299c400469ed255bbe1672605824e69e08

commit 0d6b4a299c400469ed255bbe1672605824e69e08
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Wed Feb 15 23:14:54 2017

init: Use more specific filters for early udev triggers

Filtering only on the device name forces udevadm to examine virtually
all devices. This has become more expensive with newer udev versions.
Limit the devices to be examined to the subsystem they belong to.

BUG= chromium:682578 
TEST=build and boot on kevin
  run udevadm monitor in one console
  run changed commands in other console
  verify udevadm monitor receives 'add' events for both commands

Change-Id: Id75882e4f38dfc94911a792ecd31b1b880152881
Previous-Reviewed-on: https://chromium-review.googlesource.com/433163
(cherry picked from commit e0e9ce396251dc00a50c0cfad02975e9118d7acb)
Reviewed-on: https://chromium-review.googlesource.com/441995
Reviewed-by: Mike Frysinger <vapier@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[modify] https://crrev.com/0d6b4a299c400469ed255bbe1672605824e69e08/init/udev-trigger-early.conf

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform2/+/88a9aeb3f6cdc73c24b2d362c6bef89b322a6b1b

commit 88a9aeb3f6cdc73c24b2d362c6bef89b322a6b1b
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Wed Feb 15 23:14:58 2017

init: Add platform subsystem to early udev trigger for EC devices

Some EC devices are part of the platform subystem.

BUG= chromium:682578 
TEST=boot on veyron
  run udevadm monitor in one console
  run changed command in other console
  verify udevadm monitor receives 'add' events for both 'platform' and 'chromeos' devices

Change-Id: Iae8f680b74964fb30b5ca3095bad5406e6ada6a0
Previous-Reviewed-on: https://chromium-review.googlesource.com/433452
(cherry picked from commit 0c90a258407e21141d8179083fa65e2c8273a12d)
Reviewed-on: https://chromium-review.googlesource.com/442165
Reviewed-by: Matthias Kaehlcke <mka@chromium.org>
Commit-Queue: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>

[modify] https://crrev.com/88a9aeb3f6cdc73c24b2d362c6bef89b322a6b1b/init/udev-trigger-early.conf

This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

 Issue 702257  has been merged into this issue.

Any updates? Still happening in i3 version on 63 beta

Alvaro, could you please file a new issue with all the details (especially on how to reproduce the problem)? This one has been fixed and verified long ago.