2023-12-14 21:53:11

by Mateusz Jończyk

[permalink] [raw]
Subject: [Regression] debugfs warnings when resuming from suspend on 6.7-rc5

Hello,

Since upgrading to 6.7-rc kernels, I have been getting the following error
message in dmesg
while resuming from suspend:

[   83.302944] debugfs: Directory 'iwlmvm' with parent 'netdev:wlp2s0' already
present!
[   83.302963] iwlwifi 0000:02:00.0: Failed to create debugfs directory under
netdev:wlp2s0

I have placed a dump_stack() in a respective debugfs function and obtained a
stack trace (see below).

This may be connected with recent commits by Miri and Johannes:

commit c36235acb34fb ("wifi: iwlwifi: mvm: rework debugfs handling")

commit e9dd25550770a ("wifi: iwlwifi: mvm: add a per-link debugfs")

I am ready to test any patches and to investigate further.

Hardware:

02:00.0 Network controller [0280]: Intel Corporation Wireless 7265 [8086:095a]
(rev 61)
        Subsystem: Intel Corporation Dual Band Wireless-AC 7265 [8086:5010]

Old AMD AM2+ motherboard (MSI KA780G) from around 2010.

Greetings,

Mateusz

--------------------------------------------

[   48.624560] iwlwifi 0000:02:00.0: Applying debug destination EXTERNAL_DRAM
[   48.702116] iwlwifi 0000:02:00.0: Applying debug destination EXTERNAL_DRAM
[   48.704281] iwlwifi 0000:02:00.0: FW already configured (0) - re-configuring
[   48.706863] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.706872] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.706876] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.706879] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.706882] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.706884] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.706887] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   48.708274] debugfs: Directory 'iwlmvm' with parent 'netdev:wlp2s0' already
present!
[   48.708283] CPU: 1 PID: 1331 Comm: NetworkManager Not tainted
6.7.0-rc5unif32-gf3e457d6f075 #430
[   48.708287] Hardware name: MICRO-STAR INTERNATIONAL CO.,LTD MS-7551/KA780G
(MS-7551), BIOS V16.7 08/05/2010
[   48.708290] Call Trace:
[   48.708293]  <TASK>
[   48.708297]  dump_stack_lvl+0x37/0x50
[   48.708305]  dump_stack+0x10/0x20
[   48.708308]  start_creating+0xfa/0x1a0
[   48.708317]  debugfs_create_dir+0x1b/0x170
[   48.708323]  iwl_mvm_vif_add_debugfs+0x2b/0x220 [iwlmvm]
[   48.708388]  drv_add_interface+0x240/0x270 [mac80211]
[   48.708533]  ieee80211_do_open+0x4d6/0x710 [mac80211]
[   48.708633]  ? ieee80211_check_concurrent_iface+0x180/0x230 [mac80211]
[   48.708732]  ieee80211_open+0x69/0x90 [mac80211]
[   48.708832]  __dev_open+0xf0/0x1a0
[   48.708839]  __dev_change_flags+0x190/0x200
[   48.708842]  ? skb_queue_tail+0x48/0x60
[   48.708847]  dev_change_flags+0x26/0x70
[   48.708850]  do_setlink+0x867/0x11e0
[   48.708854]  ? rtnl_getlink+0x390/0x420
[   48.708857]  ? __nla_validate_parse+0x5d/0xf90
[   48.708865]  __rtnl_newlink+0x523/0xaa0
[   48.708869]  ? rtnl_newlink+0x30/0x70
[   48.708873]  rtnl_newlink+0x49/0x70
[   48.708876]  rtnetlink_rcv_msg+0x16f/0x440
[   48.708879]  ? _raw_write_unlock_bh+0x1a/0x20
[   48.708884]  ? fib6_walker_unlink+0x49/0x60
[   48.708889]  ? fib6_walk+0x8b/0xa0
[   48.708893]  ? __pfx_rtnetlink_rcv_msg+0x10/0x10
[   48.708896]  netlink_rcv_skb+0x5b/0x110
[   48.708901]  rtnetlink_rcv+0x15/0x20
[   48.708906]  netlink_unicast+0x1b5/0x260
[   48.708909]  netlink_sendmsg+0x250/0x4d0
[   48.708913]  __sock_sendmsg+0xba/0xc0
[   48.708918]  ____sys_sendmsg+0x236/0x340
[   48.708923]  ___sys_sendmsg+0x81/0xc0
[   48.708927]  ? _copy_from_iter+0xb7/0x5d0
[   48.708932]  ? kfree+0x76/0x110
[   48.708936]  ? proc_sys_call_handler+0xb8/0x250
[   48.708942]  ? __fget_light+0xd1/0x130
[   48.708947]  __sys_sendmsg+0x65/0xc0
[   48.708951]  __x64_sys_sendmsg+0x1f/0x30
[   48.708954]  do_syscall_64+0x41/0xf0
[   48.708959]  entry_SYSCALL_64_after_hwframe+0x56/0x5e
[   48.708965] RIP: 0033:0x7feceb7cb18d
[   48.708970] Code: 28 89 54 24 1c 48 89 74 24 10 89 7c 24 08 e8 ca ee ff ff 8b
54 24 1c 48 8b 74 24 10 41 89 c0 8b 7c 24 08 b8 2e 00 00 00 0f 05 <48> 3d 00 f0
ff ff 77 2f 44 89 c7 48 89 44 24 08 e8 fe ee ff ff 48
[   48.708974] RSP: 002b:00007ffecdd37c60 EFLAGS: 00000293 ORIG_RAX:
000000000000002e
[   48.708978] RAX: ffffffffffffffda RBX: 00005638fb6c1c00 RCX: 00007feceb7cb18d
[   48.708981] RDX: 0000000000000000 RSI: 00007ffecdd37cb0 RDI: 000000000000000c
[   48.708983] RBP: 00007ffecdd37cb0 R08: 0000000000000000 R09: 0000000000000000
[   48.708985] R10: 0000000000000001 R11: 0000000000000293 R12: 00005638fb6c1c00
[   48.708987] R13: 00007ffecdd37e68 R14: 00007ffecdd37e5c R15: 0000000000000000
[   48.708991]  </TASK>
[   48.709032] iwlwifi 0000:02:00.0: Failed to create debugfs directory under
netdev:wlp2s0
[   52.403523] wlp2s0: authenticate with 50:c7:bf:2c:a9:31 (local
address=b8:9a:2a:5a:b8:56)
[   52.404492] wlp2s0: send auth to 50:c7:bf:2c:a9:31 (try 1/3)
[   52.406824] wlp2s0: authenticated
[   52.408269] wlp2s0: associate with 50:c7:bf:2c:a9:31 (try 1/3)
[   52.410136] wlp2s0: RX AssocResp from 50:c7:bf:2c:a9:31 (capab=0x11 status=0
aid=3)
[   52.412299] wlp2s0: associated



2023-12-14 21:56:24

by Mateusz Jończyk

[permalink] [raw]
Subject: Re: [Regression] debugfs warnings when resuming from suspend on 6.7-rc5

W dniu 14.12.2023 o 22:45, Mateusz Jończyk pisze:
> Hello,
>
> Since upgrading to 6.7-rc kernels, I have been getting the following error
> message in dmesg
> while resuming from suspend:
>
> [   83.302944] debugfs: Directory 'iwlmvm' with parent 'netdev:wlp2s0' already
> present!
> [   83.302963] iwlwifi 0000:02:00.0: Failed to create debugfs directory under
> netdev:wlp2s0
>
OK, now I see

https://patchwork.kernel.org/project/linux-wireless/patch/20231211085121.88a950f43e16.Id71181780994649219685887c0fcad33d387cc78@changeid/

("wifi: mac80211: don't re-add debugfs during reconfig")

Will see if this fixes the issue.

Greetings,

Mateusz


2023-12-19 12:03:25

by Johannes Berg

[permalink] [raw]
Subject: Re: [Regression] debugfs warnings when resuming from suspend on 6.7-rc5

On Thu, 2023-12-14 at 22:49 +0100, Mateusz Jończyk wrote:
> W dniu 14.12.2023 o 22:45, Mateusz Jończyk pisze:
> > Hello,
> >
> > Since upgrading to 6.7-rc kernels, I have been getting the following error
> > message in dmesg
> > while resuming from suspend:
> >
> > [   83.302944] debugfs: Directory 'iwlmvm' with parent 'netdev:wlp2s0' already
> > present!
> > [   83.302963] iwlwifi 0000:02:00.0: Failed to create debugfs directory under
> > netdev:wlp2s0
> >
> OK, now I see
>
> https://patchwork.kernel.org/project/linux-wireless/patch/20231211085121.88a950f43e16.Id71181780994649219685887c0fcad33d387cc78@changeid/
>
> ("wifi: mac80211: don't re-add debugfs during reconfig")
>
> Will see if this fixes the issue.
>

Did that work? I think we need

https://patchwork.kernel.org/project/linux-wireless/patch/20231220043149.ddd48c66ec6b.Ia81080d92129ceecf462eceb4966bab80df12060@changeid/

in addition ...

johannes

2023-12-19 21:51:04

by Mateusz Jończyk

[permalink] [raw]
Subject: Re: [Regression] debugfs warnings when resuming from suspend on 6.7-rc5

W dniu 19.12.2023 o 13:03, Johannes Berg pisze:
> On Thu, 2023-12-14 at 22:49 +0100, Mateusz Jończyk wrote:
>> W dniu 14.12.2023 o 22:45, Mateusz Jończyk pisze:
>>> Hello,
>>>
>>> Since upgrading to 6.7-rc kernels, I have been getting the following error
>>> message in dmesg
>>> while resuming from suspend:
>>>
>>> [   83.302944] debugfs: Directory 'iwlmvm' with parent 'netdev:wlp2s0' already
>>> present!
>>> [   83.302963] iwlwifi 0000:02:00.0: Failed to create debugfs directory under
>>> netdev:wlp2s0
>>>
>> OK, now I see
>>
>> https://patchwork.kernel.org/project/linux-wireless/patch/20231211085121.88a950f43e16.Id71181780994649219685887c0fcad33d387cc78@changeid/
>>
>> ("wifi: mac80211: don't re-add debugfs during reconfig")
>>
>> Will see if this fixes the issue.
>>
> Did that work? I think we need
>
> https://patchwork.kernel.org/project/linux-wireless/patch/20231220043149.ddd48c66ec6b.Ia81080d92129ceecf462eceb4966bab80df12060@changeid/
>
> in addition ...
>
> johannes

Unfortunately, these two patches together do not fix the issue.

I have tested them on top of 6.7.0-rc6, together with a patch that adds
a dump_stack() to start_creating() in fs/debugfs/inode.c in case of error.

Hardware:

02:00.0 Network controller [0280]: Intel Corporation Wireless 7265 [8086:095a]
(rev 61)
        Subsystem: Intel Corporation Dual Band Wireless-AC 7265 [8086:5010]

Old AMD AM2+ motherboard (MSI KA780G) from around 2010.

Greetings,

Mateusz

------------------------------

[   55.188244] iwlwifi 0000:02:00.0: Applying debug destination EXTERNAL_DRAM
[   55.266033] iwlwifi 0000:02:00.0: Applying debug destination EXTERNAL_DRAM
[   55.269004] iwlwifi 0000:02:00.0: FW already configured (0) - re-configuring
[   55.273661] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.273673] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.273678] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.273682] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.273686] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.273689] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.273693] ACPI: \: failed to evaluate _DSM
bf0212f2-788f-c64d-a5b3-1f738e285ade (0x1001)
[   55.274768] debugfs: Directory 'iwlmvm' with parent 'netdev:wlp2s0' already
present!
[   55.274776] CPU: 2 PID: 1327 Comm: NetworkManager Not tainted
6.7.0-rc6unif32-00003-g955274890fe4 #433
[   55.274779] Hardware name: MICRO-STAR INTERNATIONAL CO.,LTD MS-7551/KA780G
(MS-7551), BIOS V16.7 08/05/2010
[   55.274782] Call Trace:
[   55.274784]  <TASK>
[   55.274788]  dump_stack_lvl+0x37/0x50
[   55.274795]  dump_stack+0x10/0x20
[   55.274797]  start_creating+0xfa/0x1a0
[   55.274804]  debugfs_create_dir+0x1b/0x170
[   55.274809]  iwl_mvm_vif_add_debugfs+0x2b/0x220 [iwlmvm]
[   55.274860]  drv_add_interface+0x25f/0x280 [mac80211]
[   55.274979]  ieee80211_do_open+0x4d6/0x710 [mac80211]
[   55.275054]  ? ieee80211_check_concurrent_iface+0x180/0x230 [mac80211]
[   55.275128]  ieee80211_open+0x69/0x90 [mac80211]
[   55.275204]  __dev_open+0xf0/0x1a0
[   55.275209]  __dev_change_flags+0x190/0x200
[   55.275211]  ? skb_queue_tail+0x48/0x60
[   55.275215]  dev_change_flags+0x26/0x70
[   55.275217]  do_setlink+0x867/0x11e0
[   55.275220]  ? rtnl_getlink+0x390/0x420
[   55.275223]  ? __nla_validate_parse+0x5d/0xf90
[   55.275229]  __rtnl_newlink+0x523/0xaa0
[   55.275232]  ? rtnl_newlink+0x30/0x70
[   55.275235]  rtnl_newlink+0x49/0x70
[   55.275237]  rtnetlink_rcv_msg+0x16f/0x440
[   55.275239]  ? _raw_write_unlock_bh+0x1a/0x20
[   55.275243]  ? fib6_walker_unlink+0x49/0x60
[   55.275247]  ? fib6_walk+0x8b/0xa0
[   55.275249]  ? __pfx_rtnetlink_rcv_msg+0x10/0x10
[   55.275252]  netlink_rcv_skb+0x5b/0x110
[   55.275256]  rtnetlink_rcv+0x15/0x20
[   55.275259]  netlink_unicast+0x1b5/0x260
[   55.275262]  netlink_sendmsg+0x250/0x4d0
[   55.275265]  __sock_sendmsg+0xba/0xc0
[   55.275269]  ____sys_sendmsg+0x236/0x340
[   55.275273]  ___sys_sendmsg+0x81/0xc0
[   55.275276]  ? _copy_from_iter+0xb7/0x5d0
[   55.275279]  ? kfree+0x76/0x110
[   55.275283]  ? proc_sys_call_handler+0xb8/0x250
[   55.275287]  ? __fget_light+0xd1/0x130
[   55.275291]  __sys_sendmsg+0x65/0xc0
[   55.275295]  __x64_sys_sendmsg+0x1f/0x30
[   55.275297]  do_syscall_64+0x41/0xf0
[   55.275301]  entry_SYSCALL_64_after_hwframe+0x56/0x5e
[   55.275306] RIP: 0033:0x7f5a8c97418d
[   55.275309] Code: 28 89 54 24 1c 48 89 74 24 10 89 7c 24 08 e8 ca ee ff ff 8b
54 24 1c 48 8b 74 24 10 41 89 c0 8b 7c 24 08 b8 2e 00 00 00 0f 05 <48> 3d 00 f0
ff ff 77 2f 44 89 c7 48 89 44 24 08 e8 fe ee ff ff 48
[   55.275312] RSP: 002b:00007fff2c7b74e0 EFLAGS: 00000293 ORIG_RAX:
000000000000002e
[   55.275315] RAX: ffffffffffffffda RBX: 000055d5ddbf8c00 RCX: 00007f5a8c97418d
[   55.275317] RDX: 0000000000000000 RSI: 00007fff2c7b7530 RDI: 000000000000000c
[   55.275319] RBP: 00007fff2c7b7530 R08: 0000000000000000 R09: 0000000000000000
[   55.275320] R10: 000055d5ddb95010 R11: 0000000000000293 R12: 000055d5ddbf8c00
[   55.275322] R13: 00007fff2c7b76e8 R14: 00007fff2c7b76dc R15: 0000000000000000
[   55.275324]  </TASK>
[   55.275328] iwlwifi 0000:02:00.0: Failed to create debugfs directory under
netdev:wlp2s0
[   58.899942] wlp2s0: 80 MHz not supported, disabling VHT
[   58.906183] wlp2s0: authenticate with 50:c7:bf:2c:a9:32 (local
address=b8:9a:2a:5a:b8:56)
[   58.906808] wlp2s0: send auth to 50:c7:bf:2c:a9:32 (try 1/3)
[   58.908969] wlp2s0: authenticated
[   58.909602] wlp2s0: associate with 50:c7:bf:2c:a9:32 (try 1/3)
[   58.911326] wlp2s0: RX AssocResp from 50:c7:bf:2c:a9:32 (capab=0x431 status=0
aid=5)
[   58.913643] wlp2s0: associated