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;
From:   "Liu, Yongxin" <Yongxin.Liu@windriver.com>
To:     "vaibhavgupta40@gmail.com" <vaibhavgupta40@gmail.com>,
        "andrewx.bowers@intel.com" <andrewx.bowers@intel.com>,
        "anthony.l.nguyen@intel.com" <anthony.l.nguyen@intel.com>
CC:     LKML <linux-kernel@vger.kernel.org>
Subject: ixgbe: disabling already-disabled device
Thread-Topic: ixgbe: disabling already-disabled device
Thread-Index: AdcP85JsQajz+UmXRjWk+/KVlWjmHg==
Date:   Thu, 4 Mar 2021 01:47:20 +0000
Message-ID: <PH0PR11MB517500D906CDFA9CC09DFCCDE5979@PH0PR11MB5175.namprd11.prod.outlook.com>
Accept-Language: en-US
Content-Language: en-US
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-Network-Message-Id: 63f34c7c-c1f3-4a2f-c1b9-08d8deaf7302
X-MS-Exchange-CrossTenant-originalarrivaltime: 04 Mar 2021 01:47:20.2053
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 8ddb2873-a1ad-4a18-ae4e-4644631433be
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: Kgwph7y+RfICc6y9/JKjj/l7w8uYe7tocLCJwSRBELsTzWV4Rgqk/COqQU9lFOo9DSykQIUqIer3yrEXZhrBNySMZFG9fDGUTea+4I/s2c0=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: PH0PR11MB4821
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

Hello,

I am seeing the following call trace on the second run of "rtcwake -m mem -=
s 20".
After reverting commit 6f82b2558735 ("ixgbe: use generic power management")=
, the call trace disappeared.

It seems "pci_disable_device()" is used in "__ixgbe_shutdown()", however "p=
ci_enable_device_mem()" was removed in "ixgbe_resume()".
Does this cause mismatch of disable and enable?=20

Could you help to check? Thanks.

Here is the log.

root@intel-x86-64:~# echo s2idle >  /sys/power/mem_sleep   =20
root@intel-x86-64:~# cat /sys/power/mem_sleep           =20
[s2idle] deep

root@intel-x86-64:~# rtcwake -m mem -s 20
rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Wed Mar  3 05:37:01 2021
PM: suspend entry (s2idle)
Filesystems sync: 0.000 seconds
Freezing user space processes ... (elapsed 0.002 seconds) done.
OOM killer disabled.
Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
serial 00:03: disabled
sd 2:0:0:0: [sda] Synchronizing SCSI cache
sd 2:0:0:0: [sda] Stopping disk
power_meter ACPI000D:00: Found ACPI power meter.
serial 00:02: activated
serial 00:03: activated
hpet: Lost 5087 RTC interrupts
sd 2:0:0:0: [sda] Starting disk
ice 0000:ca:00.0: VSI rebuilt. VSI index 0, type ICE_VSI_PF
ice 0000:ca:00.0: VSI rebuilt. VSI index 383, type ICE_VSI_CTRL
ata1: SATA link down (SStatus 0 SControl 300)
ata2: SATA link down (SStatus 0 SControl 300)
ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
ata7: SATA link down (SStatus 0 SControl 300)
ata6: SATA link down (SStatus 0 SControl 300)
ata8: SATA link down (SStatus 0 SControl 300)
ata9: SATA link down (SStatus 0 SControl 300)
ata4: SATA link down (SStatus 0 SControl 300)
ata5: SATA link down (SStatus 0 SControl 300)
ata10: SATA link down (SStatus 0 SControl 300)
ata3.00: configured for UDMA/133
ata3.00: Enabling discard_zeroes_data
ice 0000:ca:00.1: VSI rebuilt. VSI index 0, type ICE_VSI_PF
ixgbe 0000:17:00.0: Multiqueue Enabled: Rx Queue count =3D 63, Tx Queue cou=
nt =3D 63 XDP Queue count =3D 0
ice 0000:ca:00.1: VSI rebuilt. VSI index 383, type ICE_VSI_CTRL
ixgbe 0000:17:00.1: Multiqueue Enabled: Rx Queue count =3D 63, Tx Queue cou=
nt =3D 63 XDP Queue count =3D 0
OOM killer enabled.
Restarting tasks ... done.
PM: suspend exit
igb 0000:01:00.0 eth0: igb: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow=
 Control: RX
root@intel-x86-64:~# ixgbe 0000:17:00.0 eth1: NIC Link is Up 10 Gbps, Flow =
Control: None
ixgbe 0000:17:00.1 eth2: NIC Link is Up 10 Gbps, Flow Control: None

root@intel-x86-64:~# rtcwake -m mem -s 20
rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Wed Mar  3 05:37:37 2021
PM: suspend entry (s2idle)
Filesystems sync: 0.000 seconds
Freezing user space processes ... (elapsed 0.002 seconds) done.
OOM killer disabled.
Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
serial 00:03: disabled
sd 2:0:0:0: [sda] Synchronizing SCSI cache
sd 2:0:0:0: [sda] Stopping disk
------------[ cut here ]------------
ixgbe 0000:17:00.1: disabling already-disabled device
WARNING: CPU: 60 PID: 1138 at /buildarea3/yliu15/WindRiver/kernel_upstream/=
linux/drivers/pci/pci.c:2147 pci_disable_device+0x9c/0xc0
Modules linked in: intel_rapl_msr intel_rapl_common i10nm_edac nfit libnvdi=
mm input_leds led_class ice x86_pkg_temp_thermal iTCO_wdt intel_powerclamp =
intel_pmc_bxt qat_c62x crct10dif_pclmul iTCO_vendor_support intel_qat crct1=
0dif_common coretemp watchdog aesni_intel isst_if_mmio crypto_simd i2c_i801=
 cryptd isst_if_mbox_pci dh_generic isst_if_common lpc_ich i2c_smbus wmi ac=
pi_power_meter acpi_pad sch_fq_codel openvswitch nsh nf_conncount nf_nat nf=
_conntrack nf_defrag_ipv6 nf_defrag_ipv4 fuse configfs
CPU: 60 PID: 1138 Comm: kworker/u193:17 Not tainted 5.12.0-rc1 #2

Workqueue: events_unbound async_run_entry_fn
RIP: 0010:pci_disable_device+0x9c/0xc0
Code: c6 05 d5 93 37 01 01 4d 85 e4 74 36 48 8d bb c0 00 00 00 e8 26 f0 16 =
00 4c 89 e2 48 c7 c7 e8 90 42 ac 48 89 c6 e8 c4 53 9d ff <0f> 0b eb 82 48 8=
9 df e8 d8 fe ff ff 80 a3 e1 07 00 00 df 5b 41 5c
RSP: 0018:ff6d49e649a13d10 EFLAGS: 00010286
RAX: 0000000000000000 RBX: ff4a345a47899000 RCX: 0000000000000001
RDX: 0000000080000001 RSI: ffffffffac3cda3c RDI: 00000000ffffffff
RBP: ff6d49e649a13d20 R08: 0000000000000000 R09: 0000000000000001
R10: ff6d49e6468f7d98 R11: ff6d49e649a13ac0 R12: ff4a345a476be850
R13: 0000000000000000 R14: ff4a345a47899000 R15: 0000000000000000
FS:  0000000000000000(0000) GS:ff4a345f1ff00000(0000) knlGS:000000000000000=
0
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005600c6bf5010 CR3: 000000088480a002 CR4: 0000000000771ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
 __ixgbe_shutdown+0x10a/0x1e0
 ixgbe_suspend+0x32/0x70
 pci_pm_suspend+0x87/0x160
 ? pci_pm_freeze+0xd0/0xd0
 dpm_run_callback+0x42/0x170
 __device_suspend+0x114/0x460
 async_suspend+0x1f/0xa0
 async_run_entry_fn+0x3c/0xf0
 process_one_work+0x1dd/0x410
 worker_thread+0x34/0x3f0
 ? cancel_delayed_work+0x90/0x90
 kthread+0x14c/0x170
 ? kthread_park+0x90/0x90
 ret_from_fork+0x1f/0x30
---[ end trace b6646a12cd8b3fb4 ]---
power_meter ACPI000D:00: Found ACPI power meter.
sd 2:0:0:0: [sda] Starting disk
serial 00:02: activated
serial 00:03: activated
ice 0000:ca:00.0: VSI rebuilt. VSI index 0, type ICE_VSI_PF
ice 0000:ca:00.0: VSI rebuilt. VSI index 383, type ICE_VSI_CTRL
ata1: SATA link down (SStatus 0 SControl 300)
ata2: SATA link down (SStatus 0 SControl 300)
ata9: SATA link down (SStatus 0 SControl 300)
ata5: SATA link down (SStatus 0 SControl 300)
ata7: SATA link down (SStatus 0 SControl 300)
ata8: SATA link down (SStatus 0 SControl 300)
ata10: SATA link down (SStatus 0 SControl 300)
ata6: SATA link down (SStatus 0 SControl 300)
ata4: SATA link down (SStatus 0 SControl 300)
ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
ata3.00: configured for UDMA/133
ata3.00: Enabling discard_zeroes_data
ice 0000:ca:00.1: VSI rebuilt. VSI index 0, type ICE_VSI_PF
ixgbe 0000:17:00.1: Multiqueue Enabled: Rx Queue count =3D 63, Tx Queue cou=
nt =3D 63 XDP Queue count =3D 0
ice 0000:ca:00.1: VSI rebuilt. VSI index 383, type ICE_VSI_CTRL
ixgbe 0000:17:00.0: Multiqueue Enabled: Rx Queue count =3D 63, Tx Queue cou=
nt =3D 63 XDP Queue count =3D 0
OOM killer enabled.
Restarting tasks ... done.
PM: suspend exit
root@intel-x86-64:~# igb 0000:01:00.0 eth0: igb: eth0 NIC Link is Up 1000 M=
bps Full Duplex, Flow Control: RX
ixgbe 0000:17:00.1 eth2: NIC Link is Up 10 Gbps, Flow Control: None
IPv6: ADDRCONF(NETDEV_CHANGE): eth2: link becomes ready
ixgbe 0000:17:00.0 eth1: NIC Link is Up 10 Gbps, Flow Control: None
IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready

-- Yongxin