Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
Subject: Re: Regression with PM / wakeup: Show wakeup sources stats in sysfs"
To:     Tri Vo <trong@android.com>
Cc:     "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
        "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>,
        Greg KH <gregkh@linuxfoundation.org>,
        Stephen Boyd <swboyd@chromium.org>
References: <11459cde-7f57-c95b-8cac-4301f0a2390e@gmail.com>
 <9d75a67b-87f0-161c-02d7-c9fc4efe97e7@intel.com>
 <CANA+-vBURc0ivB=UHXK5Xg_tVJOV_h9Uz_Ke4ZG3Gu_sMhfTvQ@mail.gmail.com>
From:   Florian Fainelli <f.fainelli@gmail.com>
Autocrypt: addr=f.fainelli@gmail.com; prefer-encrypt=mutual; keydata=
 xsDiBEjPuBIRBACW9MxSJU9fvEOCTnRNqG/13rAGsj+vJqontvoDSNxRgmafP8d3nesnqPyR
 xGlkaOSDuu09rxuW+69Y2f1TzjFuGpBk4ysWOR85O2Nx8AJ6fYGCoeTbovrNlGT1M9obSFGQ
 X3IzRnWoqlfudjTO5TKoqkbOgpYqIo5n1QbEjCCwCwCg3DOH/4ug2AUUlcIT9/l3pGvoRJ0E
 AICDzi3l7pmC5IWn2n1mvP5247urtHFs/uusE827DDj3K8Upn2vYiOFMBhGsxAk6YKV6IP0d
 ZdWX6fqkJJlu9cSDvWtO1hXeHIfQIE/xcqvlRH783KrihLcsmnBqOiS6rJDO2x1eAgC8meAX
 SAgsrBhcgGl2Rl5gh/jkeA5ykwbxA/9u1eEuL70Qzt5APJmqVXR+kWvrqdBVPoUNy/tQ8mYc
 nzJJ63ng3tHhnwHXZOu8hL4nqwlYHRa9eeglXYhBqja4ZvIvCEqSmEukfivk+DlIgVoOAJbh
 qIWgvr3SIEuR6ayY3f5j0f2ejUMYlYYnKdiHXFlF9uXm1ELrb0YX4GMHz80nRmxvcmlhbiBG
 YWluZWxsaSA8Zi5mYWluZWxsaUBnbWFpbC5jb20+wmYEExECACYCGyMGCwkIBwMCBBUCCAME
 FgIDAQIeAQIXgAUCVF/S8QUJHlwd3wAKCRBhV5kVtWN2DvCVAJ4u4/bPF4P3jxb4qEY8I2gS
 6hG0gACffNWlqJ2T4wSSn+3o7CCZNd7SLSDOwU0EVxvH8AEQAOqv6agYuT4x3DgFIJNv9i0e
 S443rCudGwmg+CbjXGA4RUe1bNdPHYgbbIaN8PFkXfb4jqg64SyU66FXJJJO+DmPK/t7dRNA
 3eMB1h0GbAHlLzsAzD0DKk1ARbjIusnc02aRQNsAUfceqH5fAMfs2hgXBa0ZUJ4bLly5zNbr
 r0t/fqZsyI2rGQT9h1D5OYn4oF3KXpSpo+orJD93PEDeseho1EpmMfsVH7PxjVUlNVzmZ+tc
 IDw24CDSXf0xxnaojoicQi7kzKpUrJodfhNXUnX2JAm/d0f9GR7zClpQMezJ2hYAX7BvBajb
 Wbtzwi34s8lWGI121VjtQNt64mSqsK0iQAE6OYk0uuQbmMaxbBTT63+04rTPBO+gRAWZNDmQ
 b2cTLjrOmdaiPGClSlKx1RhatzW7j1gnUbpfUl91Xzrp6/Rr9BgAZydBE/iu57KWsdMaqu84
 JzO9UBGomh9eyBWBkrBt+Fe1qN78kM7JO6i3/QI56NA4SflV+N4PPgI8TjDVaxgrfUTV0gVa
 cr9gDE5VgnSeSiOleChM1jOByZu0JTShOkT6AcSVW0kCz3fUrd4e5sS3J3uJezSvXjYDZ53k
 +0GS/Hy//7PSvDbNVretLkDWL24Sgxu/v8i3JiYIxe+F5Br8QpkwNa1tm7FK4jOd95xvYADl
 BUI1EZMCPI7zABEBAAHCwagEGBECAAkFAlcbx/ACGwICKQkQYVeZFbVjdg7BXSAEGQECAAYF
 Alcbx/AACgkQh9CWnEQHBwSJBw//Z5n6IO19mVzMy/ZLU/vu8flv0Aa0kwk5qvDyvuvfiDTd
 WQzq2PLs+obX0y1ffntluhvP+8yLzg7h5O6/skOfOV26ZYD9FeV3PIgR3QYF26p2Ocwa3B/k
 P6ENkk2pRL2hh6jaA1Bsi0P34iqC2UzzLq+exctXPa07ioknTIJ09BT31lQ36Udg7NIKalnj
 5UbkRjqApZ+Rp0RAP9jFtq1n/gjvZGyEfuuo/G+EVCaiCt3Vp/cWxDYf2qsX6JxkwmUNswuL
 C3duQ0AOMNYrT6Pn+Vf0kMboZ5UJEzgnSe2/5m8v6TUc9ZbC5I517niyC4+4DY8E2m2V2LS9
 es9uKpA0yNcd4PfEf8bp29/30MEfBWOf80b1yaubrP5y7yLzplcGRZMF3PgBfi0iGo6kM/V2
 13iD/wQ45QTV0WTXaHVbklOdRDXDHIpT69hFJ6hAKnnM7AhqZ70Qi31UHkma9i/TeLLzYYXz
 zhLHGIYaR04dFT8sSKTwTSqvm8rmDzMpN54/NeDSoSJitDuIE8givW/oGQFb0HGAF70qLgp0
 2XiUazRyRU4E4LuhNHGsUxoHOc80B3l+u3jM6xqJht2ZyMZndbAG4LyVA2g9hq2JbpX8BlsF
 skzW1kbzIoIVXT5EhelxYEGqLFsZFdDhCy8tjePOWK069lKuuFSssaZ3C4edHtkZ8gCfWWtA
 8dMsqeOIg9Trx7ZBCDOZGNAAnjYQmSb2eYOAti3PX3Ex7vI8ZhJCzsNNBEjPuBIQEAC/6NPW
 6EfQ91ZNU7e/oKWK91kOoYGFTjfdOatp3RKANidHUMSTUcN7J2mxww80AQHKjr3Yu2InXwVX
 SotMMR4UrkQX7jqabqXV5G+88bj0Lkr3gi6qmVkUPgnNkIBe0gaoM523ujYKLreal2OQ3GoJ
 PS6hTRoSUM1BhwLCLIWqdX9AdT6FMlDXhCJ1ffA/F3f3nTN5oTvZ0aVF0SvQb7eIhGVFxrlb
 WS0+dpyulr9hGdU4kzoqmZX9T/r8WCwcfXipmmz3Zt8o2pYWPMq9Utby9IEgPwultaP06MHY
 nhda1jfzGB5ZKco/XEaXNvNYADtAD91dRtNGMwRHWMotIGiWwhEJ6vFc9bw1xcR88oYBs+7p
 gbFSpmMGYAPA66wdDKGj9+cLhkd0SXGht9AJyaRA5AWB85yNmqcXXLkzzh2chIpSEawRsw8B
 rQIZXc5QaAcBN2dzGN9UzqQArtWaTTjMrGesYhN+aVpMHNCmJuISQORhX5lkjeg54oplt6Zn
 QyIsOCH3MfG95ha0TgWwyFtdxOdY/UY2zv5wGivZ3WeS0TtQf/BcGre2y85rAohFziWOzTaS
 BKZKDaBFHwnGcJi61Pnjkz82hena8OmsnsBIucsz4N0wE+hVd6AbDYN8ZcFNIDyt7+oGD1+c
 PfqLz2df6qjXzq27BBUboklbGUObNwADBQ//V45Z51Q4fRl/6/+oY5q+FPbRLDPlUF2lV6mb
 hymkpqIzi1Aj/2FUKOyImGjbLAkuBQj3uMqy+BSSXyQLG3sg8pDDe8AJwXDpG2fQTyTzQm6l
 OnaMCzosvALk2EOPJryMkOCI52+hk67cSFA0HjgTbkAv4Mssd52y/5VZR28a+LW+mJIZDurI
 Y14UIe50G99xYxjuD1lNdTa/Yv6qFfEAqNdjEBKNuOEUQOlTLndOsvxOOPa1mRUk8Bqm9BUt
 LHk3GDb8bfDwdos1/h2QPEi+eI+O/bm8YX7qE7uZ13bRWBY+S4+cd+Cyj8ezKYAJo9B+0g4a
 RVhdhc3AtW44lvZo1h2iml9twMLfewKkGV3oG35CcF9mOd7n6vDad3teeNpYd/5qYhkopQrG
 k2oRBqxyvpSLrJepsyaIpfrt5NNaH7yTCtGXcxlGf2jzGdei6H4xQPjDcVq2Ra5GJohnb/ix
 uOc0pWciL80ohtpSspLlWoPiIowiKJu/D/Y0bQdatUOZcGadkywCZc/dg5hcAYNYchc8AwA4
 2dp6w8SlIsm1yIGafWlNnfvqbRBglSTnxFuKqVggiz2zk+1wa/oP+B96lm7N4/3Aw6uy7lWC
 HvsHIcv4lxCWkFXkwsuWqzEKK6kxVpRDoEQPDj+Oy/ZJ5fYuMbkdHrlegwoQ64LrqdmiVVPC
 TwQYEQIADwIbDAUCVF/S8QUJHlwd3wAKCRBhV5kVtWN2Do+FAJ956xSz2XpDHql+Wg/2qv3b
 G10n8gCguORqNGMsVRxrlLs7/himep7MrCc=
Message-ID: <78faec4a-bf98-a731-b505-a1ccfb6e4557@gmail.com>
Date:   Fri, 29 May 2020 15:37:04 -0700
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101
 Thunderbird/68.8.0
MIME-Version: 1.0
In-Reply-To: <CANA+-vBURc0ivB=UHXK5Xg_tVJOV_h9Uz_Ke4ZG3Gu_sMhfTvQ@mail.gmail.com>
Content-Type: text/plain; charset=utf-8
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On 5/29/20 3:28 PM, Tri Vo wrote:
> On Fri, May 29, 2020 at 9:51 AM Rafael J. Wysocki
> <rafael.j.wysocki@intel.com> wrote:
>>
>> On 5/28/2020 10:46 PM, Florian Fainelli wrote:
>>> Hi,
>>>
>>> Commit c8377adfa78103be5380200eb9dab764d7ca890e ("PM / wakeup: Show
>>> wakeup sources stats in sysfs") is causing some of our tests to fail
>>> because /sys/class/net/*/device/power/wakeup_count is now 0, despite
>>> /sys/kernel/debug/wakeup_sources clearly indicating that the Ethernet
>>> device was responsible for system wake-up.
>>>
>>> What's more in looking at /sys/class/wakekup/wakeup2/event_count, we
>>> have the number of Wake-on-LAN wakeups recorded properly, but
>>> wakeup_count is desperately 0, why is that?
>>
>> I need to look at that commit in detail to find out what is going on.
> 
> It would be helpful to see the contents of
> /sys/kernel/debug/wakeup_sources, /sys/class/net/*/device/power/*, and
> /sys/class/wakekup/* corresponding to the device in question. The
> values in these files are queried from the same struct wakeup_source.
> So it's odd if wakeup_count diverges.

Most certainly, below is the information you want, the two cat
/s/k/d/wakeup_sources were done before Wake-on-LAN and after waking-up
from LAN. /sys/class/wakeup/wakeup2 maps to the Ethernet device.

The Ethernet device calls pm_wakeup_event() against the struct device
that is embedded in the platform_device that it was probed with. I will
try to debug this myself over the weekend, time permitting.


# ethtool -s eth0 wol g
# cat /sys/kernel/debug/wakeup_sources
name            active_count    event_count     wakeup_count
expire_count    active_since    total_time      max_time        last_changep
revent_suspend_time
47d580000.ethernet      0               0               0
0               0               0               0               0  0
alarmtimer      0               0               0               0
        0               0               0               0          0
47c408400.waketimer     2               2               0
0               0               0               0               6144
1               0
# pml -w20
[ 3449.937142] brcm-waketimer 47c408400.waketimer: Using sysfs
attributes, consider using 'rtcwake'
Pass 1 out of 1, mode=none, tp_al[ 3449.952654] PM: suspend entry (shallow)
l=1, cycle_tp=, sleep=, [ 3449.959004] Filesystems sync: 0.000 seconds
wakeup_time=20
[ 3449.965984] Freezing user space processes ... (elapsed 0.001 seconds)
done.
[ 3449.974087] OOM killer disabled.
[ 3449.977316] Freezing remaining freezable tasks ... (elapsed 0.006
seconds) done.
[ 3449.991114] printk: Suspending console(s) (use no_console_suspend to
debug)
AMS: System is entering S2...
[ 3450.022381] bcmgenet 47d580000.ethernet eth0: Link is Down
[ 3450.048340] Disabling non-boot CPUs ...
[ 3450.049344] CPU1: shutdown
[ 3450.050393] psci: CPU1 killed (polled 1 ms)
[ 3450.051332] Enabling non-boot CPUs ...
[ 3450.051712] Detected PIPT I-cache on CPU1
[ 3450.051812] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]
[ 3450.052435] CPU1 is up
[ 3450.683588] bcmgenet 47d580000.ethernet eth0: Link is Up - 1Gbps/Full
- flow control rx/tx
[ 3450.729677] OOM killer enabled.
[ 3450.732908] Restarting tasks ... done.
[ 3450.738539] PM: suspend exit
------------------------------
[ 3450.744239] brcm-waketimer 47c408400.waketimer: Using sysfs
attributes, consider using 'rtcwake'
# cat /sys/kernel/debug/wakeup_sources
name            active_count    event_count     wakeup_count
expire_count    active_since    total_time      max_time        last_changep
revent_suspend_time
47d580000.ethernet      1               1               0
0               0               0               0               3450
054             0
alarmtimer      0               0               0               0
        0               0               0               0          0
47c408400.waketimer     2               2               0
0               0               0               0               6144
1               0
# cat /sys/class/net/*/device/power/*
cat: read error: Input/output error
auto
0
unsupported
0
enabled
0
0
1
0
0
3450054
0
0
# ls -l /sys/class/net/eth0/device/
driver/          net/             subsystem/       wakeup/
driver_override  of_node/         uevent
modalias         power/           unimac-mdio.0/
# ls -l /sys/class/net/eth0/device/power/wakeup
wakeup                wakeup_active_count   wakeup_last_time_ms
wakeup_abort_count    wakeup_count          wakeup_max_time_ms
wakeup_active         wakeup_expire_count   wakeup_total_time_ms
# ls -l /sys/class/net/eth0/device/power/wakeup^C
# ls -l /sys/class/wakeup/wakeup
wakeup0/ wakeup1/ wakeup2/
# ls -l /sys/class/wakeup/wakeup2/
total 0
-r--r--r--    1 root     root          4096 Jan  1 00:59 active_count
-r--r--r--    1 root     root          4096 Jan  1 00:59 active_time_ms
lrwxrwxrwx    1 root     root             0 Jan  1 00:59 device ->
../../../47d580000.ethernet
-r--r--r--    1 root     root          4096 Jan  1 00:59 event_count
-r--r--r--    1 root     root          4096 Jan  1 00:59 expire_count
-r--r--r--    1 root     root          4096 Jan  1 00:59 last_change_ms
-r--r--r--    1 root     root          4096 Jan  1 00:59 max_time_ms
-r--r--r--    1 root     root          4096 Jan  1 00:59 name
-r--r--r--    1 root     root          4096 Jan  1 00:59
prevent_suspend_time_ms
lrwxrwxrwx    1 root     root             0 Jan  1 00:59 subsystem ->
../../../../../../class/wakeup
-r--r--r--    1 root     root          4096 Jan  1 00:59 total_time_ms
-rw-r--r--    1 root     root          4096 Jan  1 00:59 uevent
-r--r--r--    1 root     root          4096 Jan  1 00:59 wakeup_count
# cat /sys/class/wakeup/wakeup2/*
1
0
cat: read error: Is a directory
1
0
3450054
0
47d580000.ethernet
0
cat: read error: Is a directory
0
0
#

-- 
Florian