+ Brian Norris to check if its an existing issue he's looking at.

Log says:

2017-01-20T11:43:08.539291-08:00 ERR kernel: [    1.192987] phy phy-ff770000.syscon:pcie-phy.5: pll lock timeout!
2017-01-20T11:43:08.539293-08:00 ERR kernel: [    1.193006] phy phy-ff770000.syscon:pcie-phy.5: phy poweron failed --> -22
2017-01-20T11:43:08.539295-08:00 ERR kernel: [    1.193020] rockchip-pcie f8000000.pcie: fail to power on phy, err -22
2017-01-20T11:43:08.539298-08:00 WARNING kernel: [    1.193687] rockchip-pcie: probe of f8000000.pcie failed with error -22


I literally *just* booted up another Kevin on the latest 57 canary and saw the same problem for the first time. Nice coincidence.

This is likely a kernel regression on 57. I'll try to bisect.

Bisection says the regression is here:


7fbf867c8168b52f71875e3c9558ac0d76182e0f is the first bad commit
commit 7fbf867c8168b52f71875e3c9558ac0d76182e0f
Author: Furquan Shaikh <furquan@chromium.org>
Date:   Mon Jan 9 14:58:58 2017 -0800

    CHROMIUM: drivers: regulator: Initialize regulator init data for ACPI regulators

    https://chromium-review.googlesource.com/418142

Revert posted here:

https://chromium-review.googlesource.com/430962

Why wasn't that code sent upstream? Looks like a pretty core change that should at least be proposed... (and tested)

From a quick look of the changes, it seems like the call to devm_gpiod_get could be creating this issue. Earlier of_get_gpio looked up "gpio", but with call to devm_gpiod_get, it seems to be looking up "gpio-gpio" and "gpio-gpios" none of which would match.

I have sent the following diff to briannorris@ to try out on a kevin device:
diff --git a/drivers/regulator/fixed.c b/drivers/regulator/fixed.c
index 94c7adacf8ea..629ae1bdae81 100644
--- a/drivers/regulator/fixed.c
+++ b/drivers/regulator/fixed.c
@@ -82,7 +82,7 @@ reg_fixed_voltage_get_config(struct device *dev,
        if (init_data->constraints.boot_on)
                config->enabled_at_boot = true;
 
-       gpiod = devm_gpiod_get(dev, "gpio", GPIOD_ASIS);
+       gpiod = devm_gpiod_get(dev, NULL, GPIOD_ASIS);
 
        if (gpiod == ERR_PTR(-EPROBE_DEFER))
                return ERR_PTR(-EPROBE_DEFER);

That explanation makes sense, as my error logs show things like:

[    0.119828] reg-fixed-voltage pp1800-pcie: GPIO lookup for consumer gpio
[    0.119834] reg-fixed-voltage pp1800-pcie: using device tree for GPIO lookup
[    0.119840] of_get_named_gpiod_flags: can't parse 'gpio-gpios' property of node '/pp1800-pcie[0]'
[    0.119846] of_get_named_gpiod_flags: can't parse 'gpio-gpio' property of node '/pp1800-pcie[0]'
[    0.119851] reg-fixed-voltage pp1800-pcie: using lookup tables for GPIO lookup
[    0.119856] reg-fixed-voltage pp1800-pcie: lookup for GPIO gpio failed

I'll test your diff in a bit.

That seems to work a little better; at least, PCIe comes up fine. But I went and diff'ed /sys/kernel/debug/gpio and /sys/kernel/debug/regulator/regulator_summary. I noticed that for /gpio, you've added this entry when using your original patch + the above diff:

gpio-0   (                    |ppvar_sys           ) out lo

You seemed to have manufactured gpio 0, where we didn't request it. Anyway, your original change is pretty hard to review.

Feel free to get your stuff re-reviewed in the context of  bug 60194 . The revert is already in the CQ, to fix this bug, since regressions have higher priority.

And by  bug 60194 , I meant https://crosbug.com/p/60194 (partner tracker).

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

commit 2390de739c382423b84e1caedb90187804711851
Author: Brian Norris <briannorris@chromium.org>
Date: Fri Jan 20 21:13:57 2017

Revert "CHROMIUM: drivers: regulator: Initialize regulator init data for ACPI regulators"

This reverts commit 7fbf867c8168b52f71875e3c9558ac0d76182e0f. It broke
Kevin's PCIe:

[    1.197164] phy phy-ff770000.syscon:pcie-phy.5: pll lock timeout!
[    1.197183] phy phy-ff770000.syscon:pcie-phy.5: phy poweron failed --> -22
[    1.197198] rockchip-pcie f8000000.pcie: fail to power on phy, err -22
[    1.197860] rockchip-pcie: probe of f8000000.pcie failed with error -22

BUG= chromium:683331 
TEST=boot Kevin, check for PCIe

Change-Id: Ib2853fc292095603c15ed371dd3e23293fe7212c
Signed-off-by: Brian Norris <briannorris@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/430962
Reviewed-by: Kirtika Ruchandani <kirtika@chromium.org>

[delete] https://crrev.com/4ebd93b131fba48f12de0ad71b5b175b80a54d01/drivers/regulator/regulator_props.c
[modify] https://crrev.com/2390de739c382423b84e1caedb90187804711851/drivers/regulator/Makefile
[modify] https://crrev.com/2390de739c382423b84e1caedb90187804711851/drivers/regulator/internal.h
[modify] https://crrev.com/2390de739c382423b84e1caedb90187804711851/drivers/regulator/of_regulator.c
[modify] https://crrev.com/2390de739c382423b84e1caedb90187804711851/drivers/regulator/fixed.c
[modify] https://crrev.com/2390de739c382423b84e1caedb90187804711851/include/linux/regulator/of_regulator.h

I guess we missed the M57 branch. Requesting merge.

Is that the only entry seen:
gpio-0   (                    |ppvar_sys           ) out lo

Or are there more differences? What about the regulator summary? Do you see any differences there?

That's the only difference -- an extra gpio entry.

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/third_party/kernel/+/d9aff29ef36744d612e2567f91b8cf85362a6881

commit d9aff29ef36744d612e2567f91b8cf85362a6881
Author: Brian Norris <briannorris@chromium.org>
Date: Fri Jan 20 21:13:57 2017

Revert "CHROMIUM: drivers: regulator: Initialize regulator init data for ACPI regulators"

This reverts commit 7fbf867c8168b52f71875e3c9558ac0d76182e0f. It broke
Kevin's PCIe:

[    1.197164] phy phy-ff770000.syscon:pcie-phy.5: pll lock timeout!
[    1.197183] phy phy-ff770000.syscon:pcie-phy.5: phy poweron failed --> -22
[    1.197198] rockchip-pcie f8000000.pcie: fail to power on phy, err -22
[    1.197860] rockchip-pcie: probe of f8000000.pcie failed with error -22

BUG= chromium:683331 
TEST=boot Kevin, check for PCIe

Change-Id: Ib2853fc292095603c15ed371dd3e23293fe7212c
Signed-off-by: Brian Norris <briannorris@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/430962
Reviewed-by: Kirtika Ruchandani <kirtika@chromium.org>
(cherry picked from commit 2390de739c382423b84e1caedb90187804711851)
Reviewed-on: https://chromium-review.googlesource.com/431259

[delete] https://crrev.com/3e129a2fa543b7a693e1cacbdfbd68d8ddeebc11/drivers/regulator/regulator_props.c
[modify] https://crrev.com/d9aff29ef36744d612e2567f91b8cf85362a6881/drivers/regulator/Makefile
[modify] https://crrev.com/d9aff29ef36744d612e2567f91b8cf85362a6881/drivers/regulator/internal.h
[modify] https://crrev.com/d9aff29ef36744d612e2567f91b8cf85362a6881/drivers/regulator/of_regulator.c
[modify] https://crrev.com/d9aff29ef36744d612e2567f91b8cf85362a6881/drivers/regulator/fixed.c
[modify] https://crrev.com/d9aff29ef36744d612e2567f91b8cf85362a6881/include/linux/regulator/of_regulator.h

Ported to 57 branch. Should be fixed.

Chrome OS 9202.1.0, 57.0.2987.6

Reproduced this issue on Chrome OS 9202.7.0, 57.0.2987.11. attached log file.

Deleted: debug-logs_20170127-115328 (1).tgz 4.6 MB

debug-logs_20170127-115328 (1).tgz 4.6 MB Download

Not the same issue:

2017-01-27T11:50:53.429338-08:00 INFO kernel: [ 1268.137252] mwifiex_pcie 0000:01:00.0: info: trying to associate to 'CrOS_NetgearAC_Platform-2.4GHz' bssid e4:f4:c6:06:ba:07
2017-01-27T11:50:54.432342-08:00 INFO kernel: [ 1269.140687] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: failed,     status code=2 err=0xfffc a_id=0x3fff
2017-01-27T11:50:54.432391-08:00 INFO kernel: [ 1269.140707] mwifiex_pcie 0000:01:00.0: assoc failure: reason CONNECT_ERR_ASSOC_ERR_TIMEOUT
2017-01-27T11:50:54.432398-08:00 INFO kernel: [ 1269.140716] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: AUTH timeout
2017-01-27T11:50:54.432404-08:00 INFO kernel: [ 1269.140768] mwifiex_pcie 0000:01:00.0: info: association to bssid e4:f4:c6:06:ba:07 failed
2017-01-27T11:50:58.036202-08:00 INFO chrom[1538]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=24.0.0.207 --ui-prioritize-in-gpu-process --use-gl=egl --gpu-sandbox-failures-fatal=yes --gpu-sandbox-start-early --arc-available --enable-arc --enable-features=PointerEvent,Pepper3DImageChromium,QuickUnlockPin --passive-listeners-default=true --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --system-developer-mode --ash-enable-palette --num-raster-threads=1 --enable-drm-atomic --enable-hardware-overlays=single-fullscreen --login-profile=user --has-chromeos-keyboard --enable-touchview --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/oem_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/oem_small.jpg --default-wallpaper-is-oem --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enable-consumer-kiosk --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-manager --first-exec-after-boot --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1,*arc/*=1: cras_client: remove stream 262144
2017-01-27T11:50:59.965209-08:00 ERR shill[1763]: [ERROR:object_proxy.cc(582)] Failed to call method: fi.w1.wpa_supplicant1.Interface.Disconnect: object_path= /fi/w1/wpa_supplicant1/Interfaces/1: fi.w1.wpa_supplicant1.NotConnected: This interface is not connected
2017-01-27T11:50:59.965326-08:00 ERR shill[1763]: [ERROR:dbus_method_invoker.h(111)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.NotConnected, Message=This interface is not connected
2017-01-27T11:50:59.965378-08:00 ERR shill[1763]: [ERROR:chromeos_supplicant_interface_proxy.cc(198)] Failed to disconnect: fi.w1.wpa_supplicant1.NotConnected This interface is not connected
...
2017-01-27T11:51:06.073506-08:00 INFO kernel: [ 1280.781242] mwifiex_pcie 0000:01:00.0: info: association to bssid 00:00:00:00:00:00 failed
2017-01-27T11:51:07.525295-08:00 INFO kernel: [ 1282.233872] mwifiex_pcie 0000:01:00.0: info: trying to associate to 'GoogleGuest' bssid 6c:f3:7f:af:8e:31
2017-01-27T11:51:08.615907-08:00 INFO kernel: [ 1283.321353] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: failed,     status code=2 err=0xfffc a_id=0x3fff
2017-01-27T11:51:08.615922-08:00 INFO kernel: [ 1283.321372] mwifiex_pcie 0000:01:00.0: assoc failure: reason CONNECT_ERR_ASSOC_ERR_TIMEOUT
2017-01-27T11:51:08.615925-08:00 INFO kernel: [ 1283.321379] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: AUTH timeout
2017-01-27T11:51:08.615928-08:00 INFO kernel: [ 1283.321413] mwifiex_pcie 0000:01:00.0: info: association to bssid 6c:f3:7f:af:8e:31 failed
2017-01-27T11:51:09.977275-08:00 INFO kernel: [ 1284.685694] mwifiex_pcie 0000:01:00.0: info: trying to associate to 'GoogleGuest' bssid 6c:f3:7f:af:8d:51
2017-01-27T11:51:11.070391-08:00 INFO kernel: [ 1285.778546] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: failed,     status code=2 err=0xfffc a_id=0x3fff
2017-01-27T11:51:11.070414-08:00 INFO kernel: [ 1285.778567] mwifiex_pcie 0000:01:00.0: assoc failure: reason CONNECT_ERR_ASSOC_ERR_TIMEOUT
2017-01-27T11:51:11.070593-08:00 INFO kernel: [ 1285.778575] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: AUTH timeout
2017-01-27T11:51:11.070597-08:00 INFO kernel: [ 1285.778612] mwifiex_pcie 0000:01:00.0: info: association to bssid 6c:f3:7f:af:8d:51 failed
2017-01-27T11:51:12.347302-08:00 INFO kernel: [ 1287.055697] mwifiex_pcie 0000:01:00.0: info: trying to associate to 'GoogleGuest' bssid 6c:f3:7f:af:8f:71
2017-01-27T11:51:13.425560-08:00 INFO kernel: [ 1288.133518] mwifiex_pcie 0000:01:00.0: ASSOC_RESP: failed,     status code=2 err=0xfffc a_id=0x3fff


Looks like crosbug.com/p/59702

Brian,
Do you think its worth using a packet capture here? (I am interested in proving/disproving the theory that we cannot hear the AP sending out the assoc response)