From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753186AbdKVXNc (ORCPT ); Wed, 22 Nov 2017 18:13:32 -0500 Received: from mga06.intel.com ([134.134.136.31]:2256 "EHLO mga06.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752651AbdKVXNa (ORCPT ); Wed, 22 Nov 2017 18:13:30 -0500 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.44,438,1505804400"; d="scan'208";a="5359154" Date: Thu, 23 Nov 2017 07:13:24 +0800 From: Fengguang Wu To: Tushar Dave Cc: intel-wired-lan@lists.osuosl.org, Jeff Kirsher , Linus Torvalds , "David S. Miller" , Sasha Neftin , Dima Ruinskiy , Raanan Avargil , Jacob Keller , Thomas Gleixner , Konstantin Khlebnikov , Bernd Faust , stephen hemminger , netdev@vger.kernel.org, linux-kernel@vger.kernel.org, lkp@01.org Subject: Re: [e1000_shutdown] e1000 0000:00:03.0: disabling already-disabled device Message-ID: <20171122231324.dofyw6maxkh5frqv@wfg-t540p.sh.intel.com> References: <20171121124148.poknfqmuef32tbdn@wfg-t540p.sh.intel.com> <7fe10136-8f99-c0e8-2a3a-93c34915a95a@oracle.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii; format=flowed Content-Disposition: inline In-Reply-To: <7fe10136-8f99-c0e8-2a3a-93c34915a95a@oracle.com> User-Agent: NeoMutt/20170609 (1.8.3) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Wed, Nov 22, 2017 at 03:40:52AM +0530, Tushar Dave wrote: > > >On 11/21/2017 06:11 PM, Fengguang Wu wrote: >> Hello, >> >> FYI this happens in mainline kernel 4.14.0-01330-g3c07399. >> It happens since 4.13 . >> >> It occurs in 3 out of 162 boots. >> >> >> [ 44.637743] advantechwdt: Unexpected close, not stopping watchdog! >> [ 44.997548] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input6 >> [ 45.013419] e1000 0000:00:03.0: disabling already-disabled device >> [ 45.013447] ------------[ cut here ]------------ >> [ 45.014868] WARNING: CPU: 1 PID: 71 at drivers/pci/pci.c:1641 pci_disable_device+0xa1/0x105: >> pci_disable_device at drivers/pci/pci.c:1640 >> [ 45.016171] CPU: 1 PID: 71 Comm: rcu_perf_shutdo Not tainted 4.14.0-01330-g3c07399 #1 >> [ 45.017197] task: ffff88011bee9e40 task.stack: ffffc90000860000 >> [ 45.017987] RIP: 0010:pci_disable_device+0xa1/0x105: >> pci_disable_device at drivers/pci/pci.c:1640 >> [ 45.018603] RSP: 0000:ffffc90000863e30 EFLAGS: 00010286 >> [ 45.019282] RAX: 0000000000000035 RBX: ffff88013a230008 RCX: 0000000000000000 >> [ 45.020182] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000203 >> [ 45.021084] RBP: ffff88013a3f31e8 R08: 0000000000000001 R09: 0000000000000000 >> [ 45.021986] R10: ffffffff827ec29c R11: 0000000000000002 R12: 0000000000000001 >> [ 45.022946] R13: ffff88013a230008 R14: ffff880117802b20 R15: ffffc90000863e8f >> [ 45.023842] FS: 0000000000000000(0000) GS:ffff88013fd00000(0000) knlGS:0000000000000000 >> [ 45.024863] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 >> [ 45.025583] CR2: ffffc900006d4000 CR3: 000000000220f000 CR4: 00000000000006a0 >> [ 45.026478] Call Trace: >> [ 45.026811] __e1000_shutdown+0x1d4/0x1e2: >> __e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:5162 >> [ 45.027344] ? rcu_perf_cleanup+0x2a1/0x2a1: >> rcu_perf_shutdown at kernel/rcu/rcuperf.c:627 >> [ 45.027883] e1000_shutdown+0x14/0x3a: >> e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:5235 >> [ 45.028351] device_shutdown+0x110/0x1aa: >> device_shutdown at drivers/base/core.c:2807 >> [ 45.028858] kernel_power_off+0x31/0x64: >> kernel_power_off at kernel/reboot.c:260 >> [ 45.029343] rcu_perf_shutdown+0x9b/0xa7: >> rcu_perf_shutdown at kernel/rcu/rcuperf.c:637 >> [ 45.029852] ? __wake_up_common_lock+0xa2/0xa2: >> autoremove_wake_function at kernel/sched/wait.c:376 >> [ 45.030414] kthread+0x126/0x12e: >> kthread at kernel/kthread.c:233 >> [ 45.030834] ? __kthread_bind_mask+0x8e/0x8e: >> kthread at kernel/kthread.c:190 >> [ 45.031399] ? ret_from_fork+0x1f/0x30: >> ret_from_fork at arch/x86/entry/entry_64.S:443 >> [ 45.031883] ? kernel_init+0xa/0xf5: >> kernel_init at init/main.c:997 >> [ 45.032325] ret_from_fork+0x1f/0x30: >> ret_from_fork at arch/x86/entry/entry_64.S:443 >> [ 45.032777] Code: 00 48 85 ed 75 07 48 8b ab a8 00 00 00 48 8d bb 98 00 00 00 e8 aa d1 11 00 48 89 ea 48 89 c6 48 c7 c7 d8 e4 0b 82 e8 55 7d da ff <0f> ff b9 01 00 00 00 31 d2 be 01 00 00 00 48 c7 c7 f0 b1 61 82 >> [ 45.035222] ---[ end trace c257137b1b1976ef ]--- >> [ 45.037838] ACPI: Preparing to enter system sleep state S5 >> >> Attached the full dmesg, kconfig and reproduce scripts. >Looks like e1000 pci/pxi-x device is already suspended. And therefore >call to e1000_suspend() -> __e1000_shutdown() -> pci_disable_device() >already had disabled the device. >Disabling device again by e1000_shutdown handler during system shutdown >causes warning at drivers/pci/pci.c:1641. > >I think function __e1000_shutdown should just return if device is >already suspended! > >I don't have e1000 hardware to test right now. So if this seems logical >to others I will send a patch. Tushar, it happens on QEMU boot testing, so do not rely on e1000 HW. Unless you'd like to prevent regressions on real HW. The original report attached a reproduce script to run the QEMU test. Or you may send me the patch for testing. Thanks, Fengguang From mboxrd@z Thu Jan 1 00:00:00 1970 From: Fengguang Wu Date: Thu, 23 Nov 2017 07:13:24 +0800 Subject: [Intel-wired-lan] [e1000_shutdown] e1000 0000:00:03.0: disabling already-disabled device In-Reply-To: <7fe10136-8f99-c0e8-2a3a-93c34915a95a@oracle.com> References: <20171121124148.poknfqmuef32tbdn@wfg-t540p.sh.intel.com> <7fe10136-8f99-c0e8-2a3a-93c34915a95a@oracle.com> Message-ID: <20171122231324.dofyw6maxkh5frqv@wfg-t540p.sh.intel.com> MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit To: intel-wired-lan@osuosl.org List-ID: On Wed, Nov 22, 2017 at 03:40:52AM +0530, Tushar Dave wrote: > > >On 11/21/2017 06:11 PM, Fengguang Wu wrote: >> Hello, >> >> FYI this happens in mainline kernel 4.14.0-01330-g3c07399. >> It happens since 4.13 . >> >> It occurs in 3 out of 162 boots. >> >> >> [ 44.637743] advantechwdt: Unexpected close, not stopping watchdog! >> [ 44.997548] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input6 >> [ 45.013419] e1000 0000:00:03.0: disabling already-disabled device >> [ 45.013447] ------------[ cut here ]------------ >> [ 45.014868] WARNING: CPU: 1 PID: 71 at drivers/pci/pci.c:1641 pci_disable_device+0xa1/0x105: >> pci_disable_device at drivers/pci/pci.c:1640 >> [ 45.016171] CPU: 1 PID: 71 Comm: rcu_perf_shutdo Not tainted 4.14.0-01330-g3c07399 #1 >> [ 45.017197] task: ffff88011bee9e40 task.stack: ffffc90000860000 >> [ 45.017987] RIP: 0010:pci_disable_device+0xa1/0x105: >> pci_disable_device at drivers/pci/pci.c:1640 >> [ 45.018603] RSP: 0000:ffffc90000863e30 EFLAGS: 00010286 >> [ 45.019282] RAX: 0000000000000035 RBX: ffff88013a230008 RCX: 0000000000000000 >> [ 45.020182] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000203 >> [ 45.021084] RBP: ffff88013a3f31e8 R08: 0000000000000001 R09: 0000000000000000 >> [ 45.021986] R10: ffffffff827ec29c R11: 0000000000000002 R12: 0000000000000001 >> [ 45.022946] R13: ffff88013a230008 R14: ffff880117802b20 R15: ffffc90000863e8f >> [ 45.023842] FS: 0000000000000000(0000) GS:ffff88013fd00000(0000) knlGS:0000000000000000 >> [ 45.024863] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 >> [ 45.025583] CR2: ffffc900006d4000 CR3: 000000000220f000 CR4: 00000000000006a0 >> [ 45.026478] Call Trace: >> [ 45.026811] __e1000_shutdown+0x1d4/0x1e2: >> __e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:5162 >> [ 45.027344] ? rcu_perf_cleanup+0x2a1/0x2a1: >> rcu_perf_shutdown at kernel/rcu/rcuperf.c:627 >> [ 45.027883] e1000_shutdown+0x14/0x3a: >> e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:5235 >> [ 45.028351] device_shutdown+0x110/0x1aa: >> device_shutdown at drivers/base/core.c:2807 >> [ 45.028858] kernel_power_off+0x31/0x64: >> kernel_power_off at kernel/reboot.c:260 >> [ 45.029343] rcu_perf_shutdown+0x9b/0xa7: >> rcu_perf_shutdown at kernel/rcu/rcuperf.c:637 >> [ 45.029852] ? __wake_up_common_lock+0xa2/0xa2: >> autoremove_wake_function at kernel/sched/wait.c:376 >> [ 45.030414] kthread+0x126/0x12e: >> kthread at kernel/kthread.c:233 >> [ 45.030834] ? __kthread_bind_mask+0x8e/0x8e: >> kthread at kernel/kthread.c:190 >> [ 45.031399] ? ret_from_fork+0x1f/0x30: >> ret_from_fork at arch/x86/entry/entry_64.S:443 >> [ 45.031883] ? kernel_init+0xa/0xf5: >> kernel_init at init/main.c:997 >> [ 45.032325] ret_from_fork+0x1f/0x30: >> ret_from_fork at arch/x86/entry/entry_64.S:443 >> [ 45.032777] Code: 00 48 85 ed 75 07 48 8b ab a8 00 00 00 48 8d bb 98 00 00 00 e8 aa d1 11 00 48 89 ea 48 89 c6 48 c7 c7 d8 e4 0b 82 e8 55 7d da ff <0f> ff b9 01 00 00 00 31 d2 be 01 00 00 00 48 c7 c7 f0 b1 61 82 >> [ 45.035222] ---[ end trace c257137b1b1976ef ]--- >> [ 45.037838] ACPI: Preparing to enter system sleep state S5 >> >> Attached the full dmesg, kconfig and reproduce scripts. >Looks like e1000 pci/pxi-x device is already suspended. And therefore >call to e1000_suspend() -> __e1000_shutdown() -> pci_disable_device() >already had disabled the device. >Disabling device again by e1000_shutdown handler during system shutdown >causes warning at drivers/pci/pci.c:1641. > >I think function __e1000_shutdown should just return if device is >already suspended! > >I don't have e1000 hardware to test right now. So if this seems logical >to others I will send a patch. Tushar, it happens on QEMU boot testing, so do not rely on e1000 HW. Unless you'd like to prevent regressions on real HW. The original report attached a reproduce script to run the QEMU test. Or you may send me the patch for testing. Thanks, Fengguang From mboxrd@z Thu Jan 1 00:00:00 1970 Content-Type: multipart/mixed; boundary="===============3024718483227029704==" MIME-Version: 1.0 From: Fengguang Wu To: lkp@lists.01.org Subject: Re: [e1000_shutdown] e1000 0000:00:03.0: disabling already-disabled device Date: Thu, 23 Nov 2017 07:13:24 +0800 Message-ID: <20171122231324.dofyw6maxkh5frqv@wfg-t540p.sh.intel.com> In-Reply-To: <7fe10136-8f99-c0e8-2a3a-93c34915a95a@oracle.com> List-Id: --===============3024718483227029704== Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable On Wed, Nov 22, 2017 at 03:40:52AM +0530, Tushar Dave wrote: > > >On 11/21/2017 06:11 PM, Fengguang Wu wrote: >> Hello, >> >> FYI this happens in mainline kernel 4.14.0-01330-g3c07399. >> It happens since 4.13 . >> >> It occurs in 3 out of 162 boots. >> >> >> [ 44.637743] advantechwdt: Unexpected close, not stopping watchdog! >> [ 44.997548] input: ImExPS/2 Generic Explorer Mouse as /devices/platfo= rm/i8042/serio1/input/input6 >> [ 45.013419] e1000 0000:00:03.0: disabling already-disabled device >> [ 45.013447] ------------[ cut here ]------------ >> [ 45.014868] WARNING: CPU: 1 PID: 71 at drivers/pci/pci.c:1641 pci_dis= able_device+0xa1/0x105: >> pci_disable_device at drivers/pci/pci.c:1640 >> [ 45.016171] CPU: 1 PID: 71 Comm: rcu_perf_shutdo Not tainted 4.14.0-0= 1330-g3c07399 #1 >> [ 45.017197] task: ffff88011bee9e40 task.stack: ffffc90000860000 >> [ 45.017987] RIP: 0010:pci_disable_device+0xa1/0x105: >> pci_disable_device at drivers/pci/pci.c:1640 >> [ 45.018603] RSP: 0000:ffffc90000863e30 EFLAGS: 00010286 >> [ 45.019282] RAX: 0000000000000035 RBX: ffff88013a230008 RCX: 00000000= 00000000 >> [ 45.020182] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000= 00000203 >> [ 45.021084] RBP: ffff88013a3f31e8 R08: 0000000000000001 R09: 00000000= 00000000 >> [ 45.021986] R10: ffffffff827ec29c R11: 0000000000000002 R12: 00000000= 00000001 >> [ 45.022946] R13: ffff88013a230008 R14: ffff880117802b20 R15: ffffc900= 00863e8f >> [ 45.023842] FS: 0000000000000000(0000) GS:ffff88013fd00000(0000) knl= GS:0000000000000000 >> [ 45.024863] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 >> [ 45.025583] CR2: ffffc900006d4000 CR3: 000000000220f000 CR4: 00000000= 000006a0 >> [ 45.026478] Call Trace: >> [ 45.026811] __e1000_shutdown+0x1d4/0x1e2: >> __e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:= 5162 >> [ 45.027344] ? rcu_perf_cleanup+0x2a1/0x2a1: >> rcu_perf_shutdown at kernel/rcu/rcuperf.c:627 >> [ 45.027883] e1000_shutdown+0x14/0x3a: >> e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:52= 35 >> [ 45.028351] device_shutdown+0x110/0x1aa: >> device_shutdown at drivers/base/core.c:2807 >> [ 45.028858] kernel_power_off+0x31/0x64: >> kernel_power_off at kernel/reboot.c:260 >> [ 45.029343] rcu_perf_shutdown+0x9b/0xa7: >> rcu_perf_shutdown at kernel/rcu/rcuperf.c:637 >> [ 45.029852] ? __wake_up_common_lock+0xa2/0xa2: >> autoremove_wake_function at kernel/sched/wait.c:376 >> [ 45.030414] kthread+0x126/0x12e: >> kthread at kernel/kthread.c:233 >> [ 45.030834] ? __kthread_bind_mask+0x8e/0x8e: >> kthread at kernel/kthread.c:190 >> [ 45.031399] ? ret_from_fork+0x1f/0x30: >> ret_from_fork at arch/x86/entry/entry_64.S:443 >> [ 45.031883] ? kernel_init+0xa/0xf5: >> kernel_init at init/main.c:997 >> [ 45.032325] ret_from_fork+0x1f/0x30: >> ret_from_fork at arch/x86/entry/entry_64.S:443 >> [ 45.032777] Code: 00 48 85 ed 75 07 48 8b ab a8 00 00 00 48 8d bb 98 = 00 00 00 e8 aa d1 11 00 48 89 ea 48 89 c6 48 c7 c7 d8 e4 0b 82 e8 55 7d da = ff <0f> ff b9 01 00 00 00 31 d2 be 01 00 00 00 48 c7 c7 f0 b1 61 82 >> [ 45.035222] ---[ end trace c257137b1b1976ef ]--- >> [ 45.037838] ACPI: Preparing to enter system sleep state S5 >> >> Attached the full dmesg, kconfig and reproduce scripts. >Looks like e1000 pci/pxi-x device is already suspended. And therefore >call to e1000_suspend() -> __e1000_shutdown() -> pci_disable_device() >already had disabled the device. >Disabling device again by e1000_shutdown handler during system shutdown >causes warning at drivers/pci/pci.c:1641. > >I think function __e1000_shutdown should just return if device is >already suspended! > >I don't have e1000 hardware to test right now. So if this seems logical >to others I will send a patch. Tushar, it happens on QEMU boot testing, so do not rely on e1000 HW. Unless you'd like to prevent regressions on real HW. The original report attached a reproduce script to run the QEMU test. Or you may send me the patch for testing. Thanks, Fengguang --===============3024718483227029704==--