Bug 216368

Created attachment 301579 [details]
dmesg (kernel 6.0-rc1, PowerMac G5 11,2), 2nd time

Created attachment 301580 [details]
kernel .config (kernel 6.0-rc1, PowerMac G5 11,2)

That might be a consequence of commit 41f20d6db2b6 ("powerpc/irq: Increase stack_overflow detection limit when KASAN is enabled") which increased the limit from 2k to 4k for PPC64.

This happens when you get an IRQ while being deep into BTRFS handling it seems.

It should be investigated with BTRFS team why the callstack is so deep.

(In reply to Christophe Leroy from comment #3)

> It should be investigated with BTRFS team why the callstack is so deep.

Did anyone forward this to the Btrfs team? if so: where? If not I guess I can do that.

(In reply to The Linux kernel's regression tracker (Thorsten Leemhuis) from comment #4)
> Did anyone forward this to the Btrfs team? if so: where? If not I guess I
> can do that.
I added David Sterba (dsterba@suse.com) to the CC list, who is a maintainer. Don't know whether that's enough.

(In reply to Christophe Leroy from comment #3)
> This happens when you get an IRQ while being deep into BTRFS handling it
> seems.
> 
> It should be investigated with BTRFS team why the callstack is so deep.

There's nothing strange on the call stack, contains all functions that are expected when handling a page fault, looking up internal structures and then passing to block layer to get the bytes from the device.

Deep stack, measured by number of functions and also size is normal for filesystrems and we try to keep the size sane, so far we haven't seen such problems on x86_64, the overall stack size is 16K an on debug kernel there are about 6K consumed at maximum (reported by CONFIG_DEBUG_STACK_USAGE=y and CONFIG_SCHED_STACK_END_CHECK=y), the lowest value found I see in my logs is 10576.

That is on a simple IO stack, ie. what's below the filesystem, as you can see the mblk-mq, NVMe and DMA also cut some stack space, but this also does not seem suspicious. What could be significant is layering with MD, device mapper, NFS, networking.

The first number in the stack trace is the stack pointer, calculating what btrfs itself takes:

[c000000019da5cf0] [c0000000004d66b4] .btrfs_submit_bio+0x274/0x5c0
[c000000019da5e00] [c000000000481f44] .btrfs_submit_metadata_bio+0x54/0x110
[c000000019da5e80] [c0000000004bd828] .submit_one_bio+0xb8/0x130
[c000000019da5f00] [c0000000004c84b0] .read_extent_buffer_pages+0x310/0x750
[c000000019da6020] [c000000000481b48] .btrfs_read_extent_buffer+0xd8/0x1b0
[c000000019da60f0] [c00000000048208c] .read_tree_block+0x5c/0x130
[c000000019da6190] [c0000000004609a8] .read_block_for_search+0x2c8/0x410
[c000000019da62b0] [c000000000466a30] .btrfs_search_slot+0x380/0xcf0
[c000000019da6400] [c00000000047adf4] .btrfs_lookup_csum+0x64/0x1d0
[c000000019da64d0] [c00000000047b754] .btrfs_lookup_bio_sums+0x274/0x6e0
[c000000019da6630] [c000000000505d18] .btrfs_submit_compressed_read+0x3b8/0x520
[c000000019da6720] [c0000000004954b4] .btrfs_submit_data_read_bio+0xc4/0xe0
[c000000019da67b0] [c0000000004bd7fc] .submit_one_bio+0x8c/0x130
[c000000019da6830] [c0000000004c4478] .submit_extent_page+0x548/0x590
[c000000019da6980] [c0000000004c4f80] .btrfs_do_readpage+0x330/0x970
[c000000019da6ad0] [c0000000004c67f4] .extent_readahead+0x2b4/0x430
[c000000019da6c70] [c000000000490440] .btrfs_readahead+0x10/0x30

0xc000000019da6c70 - 0xc000000019da5cf0 = 3968

That's on par with my expectation.

Total stack space is (from syscall to the irq handler):

0xc000000019da7e10 - 0xc000000019da4c00 = 12816

That's getting close to 16K but still a few kilobytes before overflow, the IRQ has it's own stack (that needs to be set up from the kthread/process context).

As you mention KASAN, that can add some stack consumption due to padding and alignment, but so far I don't know what exactly is the warning measuring. Calculating back from do_IRQ by 3072 it's roughly 0xc000000019da5910, inside blk_mq_flush_plug_list.

I remember some build reports from PPC that due to a different compiler used the function inlining caused increased stack space consumption (eg. due to aggressive optimizations that unrolled loops too much using several additional temporary variables). So that should be investigated too before blaming btrfs.

Created attachment 303424 [details]
dmesg (6.1.0, PowerMac G5 11,2)

Still in v6.1.0. Happens sometimes at boot on my G5:

[...]
Stack Depot allocating hash table of 1048576 entries with kvcalloc
nouveau 0000:0a:00.0: DRM: Setting dpms mode 3 on TV encoder (output 4)
do_IRQ: stack overflow: 3440
CPU: 0 PID: 264 Comm: NetworkManager Tainted: G                T  6.1.0-gentoo-PMacG5 #2
Hardware name: PowerMac11,2 PPC970MP 0x440101 PowerMac
Call Trace:
[c00000000fff7e80] [c000000000b24980] .dump_stack_lvl+0x7c/0xd8 (unreliable)
[c00000000fff7f10] [c000000000010db4] .__do_irq+0x124/0x130
[c00000000fff7f90] [c0000000000114f8] .__do_IRQ+0x78/0x130
[c000000015c5cd70] [0000000000000001] 0x1
[c000000015c5ce00] [c0000000000116b4] .do_IRQ+0x104/0x250
[c000000015c5ce80] [c000000000008034] hardware_interrupt_common_virt+0x214/0x220
--- interrupt: 500 at .dart_cache_sync+0x0/0x100
NIP:  c000000000063860 LR: c000000000063ce4 CTR: 0000000000000000
REGS: c000000015c5cef0 TRAP: 0500   Tainted: G                T   (6.1.0-gentoo-PMacG5)
MSR:  900000000200b032 <SF,HV,VEC,EE,FP,ME,IR,DR,RI>  CR: 44224280  XER: 20000000
IRQMASK: 0 
GPR00: c000000000036620 c000000015c5d190 c000000000d9d500 c00000007f00962c 
GPR04: 0000000000000001 0000000000000001 c000000018e2e000 0000000000000002 
GPR08: c00000007f00962c 0000000080018e2d c00000007f009630 000000000258b000 
GPR12: 0000000000001000 c0000000014ba000 0000000000000001 0000000000000001 
GPR16: 0000000000000001 c0000000177f4000 0000000000000001 ffffffffffffffff 
GPR20: c0000000177f4080 0000000000000002 c0000000018cc0d0 000000000258b000 
GPR24: 0000000000001000 c0000000177f4000 0000000000000008 0000000000000004 
GPR28: 0000000000000001 0000000000000001 0000000000000001 000000000000258b 
NIP [c000000000063860] .dart_cache_sync+0x0/0x100
LR [c000000000063ce4] .dart_build+0x74/0x2b0
--- interrupt: 500
[c000000015c5d190] [0000000000000001] 0x1 (unreliable)
[c000000015c5d230] [c000000000036620] .ppc_iommu_map_sg+0x1f0/0x540
[c000000015c5d350] [c0000000000352bc] .dma_iommu_map_sg+0x4c/0x90
[c000000015c5d3c0] [c000000000128098] .__dma_map_sg_attrs+0x168/0x1e0
[c000000015c5d450] [c000000000128188] .dma_map_sgtable+0x28/0x70
[c000000015c5d4d0] [c000000000869588] .nvme_prep_rq.part.0+0xd8/0xc00
[c000000015c5d5d0] [c00000000086a134] .nvme_queue_rq+0x84/0x2a0
[c000000015c5d670] [c00000000063d450] .blk_mq_dispatch_rq_list+0x260/0xb30
[c000000015c5d7b0] [c0000000006463a0] .blk_mq_do_dispatch_sched+0x3f0/0x4a0
[c000000015c5d8d0] [c000000000646860] .__blk_mq_sched_dispatch_requests+0x170/0x210
[c000000015c5d970] [c0000000006469bc] .blk_mq_sched_dispatch_requests+0x5c/0xc0
[c000000015c5d9f0] [c000000000639f48] .__blk_mq_run_hw_queue+0xd8/0x130
[c000000015c5da70] [c000000000646ed8] .blk_mq_sched_insert_requests+0xb8/0x2b0
[c000000015c5db20] [c00000000063e294] .blk_mq_flush_plug_list+0x1e4/0x3a0
[c000000015c5dbf0] [c00000000063e580] .blk_add_rq_to_plug+0x130/0x140
[c000000015c5dc70] [c00000000063eb2c] .blk_mq_submit_bio+0x23c/0x680
[c000000015c5dd60] [c000000000628b44] .__submit_bio+0x1b4/0x330
[c000000015c5de00] [c000000000629490] .submit_bio_noacct_nocheck+0x300/0x390
[c000000015c5deb0] [c0000000005129c4] .btrfs_submit_dev_bio+0xa4/0x190
[c000000015c5df30] [c00000000051e034] .btrfs_submit_bio+0x444/0x4c0
[c000000015c5e000] [c0000000004c5840] .btrfs_submit_metadata_bio+0x60/0x200
[c000000015c5e090] [c0000000005068f8] .submit_one_bio+0xf8/0x1b0
[c000000015c5e110] [c00000000050e5c4] .read_extent_buffer_pages+0x434/0x860
[c000000015c5e220] [c0000000004c5418] .btrfs_read_extent_buffer+0xd8/0x1d0
[c000000015c5e2f0] [c0000000004c5a7c] .read_tree_block+0x5c/0x190
[c000000015c5e390] [c0000000004a1654] .read_block_for_search+0x324/0x460
[c000000015c5e4a0] [c0000000004a8758] .btrfs_search_slot+0x568/0xe30
[c000000015c5e5e0] [c0000000004be004] .btrfs_lookup_csum+0x74/0x250
[c000000015c5e6c0] [c0000000004bea7c] .btrfs_lookup_bio_sums+0x27c/0x700
[c000000015c5e820] [c000000000550708] .btrfs_submit_compressed_read+0x448/0x610
[c000000015c5e920] [c0000000004da884] .btrfs_submit_data_read_bio+0x114/0x150
[c000000015c5e9b0] [c0000000005068a4] .submit_one_bio+0xa4/0x1b0
[c000000015c5ea30] [c000000000506eb8] .submit_extent_page+0x508/0x530
[c000000015c5eb80] [c00000000050a960] .btrfs_do_readpage+0x2d0/0x850
[c000000015c5ecb0] [c00000000050c2a4] .extent_readahead+0x2b4/0x450
[c000000015c5ee40] [c0000000004d4e90] .btrfs_readahead+0x10/0x30
[c000000015c5eeb0] [c00000000023eb44] .read_pages+0xa4/0x390
[c000000015c5ef80] [c00000000023efcc] .page_cache_ra_unbounded+0x19c/0x270
[c000000015c5f060] [c0000000002315b4] .filemap_fault+0x584/0xa10
[c000000015c5f180] [c00000000027f248] .__do_fault+0x58/0x120
[c000000015c5f200] [c000000000285e48] .__handle_mm_fault+0xbc8/0x10f0
[c000000015c5f350] [c000000000286490] .handle_mm_fault+0x120/0x3c0
[c000000015c5f400] [c000000000040af8] .___do_page_fault+0x218/0xa00
[c000000015c5f4b0] [c0000000000413f0] .hash__do_page_fault+0x20/0xf0
[c000000015c5f530] [c000000000048608] .do_hash_fault+0x2b8/0x3c0
[c000000015c5f5b0] [c0000000000078a8] data_access_common_virt+0x198/0x1f0
--- interrupt: 300 at .__arch_clear_user+0x5c/0x160
NIP:  c00000000005590c LR: c0000000003bbcac CTR: 000000000000000d
REGS: c000000015c5f620 TRAP: 0300   Tainted: G                T   (6.1.0-gentoo-PMacG5)
MSR:  900000000200b032 <SF,HV,VEC,EE,FP,ME,IR,DR,RI>  CR: 48428828  XER: 20000000
DAR: 000000013e036e48 DSISR: 42000000 IRQMASK: 0 
GPR00: 0000000000000000 c000000015c5f8c0 c000000000d9d500 000000013e036e48 
GPR04: 00000000000001b8 0000000000000000 000000000000000d 0000000000000000 
GPR08: 000000013e036e48 0000000000000000 00003ffffffff000 0000000000000000 
GPR12: 0000000000000000 c0000000014ba000 0000400000000000 c000000013f6f5f8 
GPR16: 0000000000000009 0000000000000000 00000000004b0990 00000000004c4328 
GPR20: 00000000004fa688 00000000004f6e48 c000000013f68800 c000000015c46c80 
GPR24: 0000000000000000 000000013e036e48 000000013db40000 c000000017830340 
GPR28: c000000013895680 0000000000000000 c000000013f6f400 c0000000013da970 
NIP [c00000000005590c] .__arch_clear_user+0x5c/0x160
LR [c0000000003bbcac] .padzero+0x7c/0x170
--- interrupt: 300
[c000000015c5f8c0] [c0000000003baa84] .set_brk+0x74/0xb0 (unreliable)
[c000000015c5f940] [c0000000003bc7f4] .load_elf_binary+0x854/0x1c40
[c000000015c5faa0] [c00000000032fffc] .bprm_execve+0x29c/0x730
[c000000015c5fb80] [c000000000330670] .do_execveat_common.isra.0+0x1e0/0x330
[c000000015c5fc50] [c000000000331904] .__se_sys_execve+0x44/0x80
[c000000015c5fcd0] [c000000000023e28] .system_call_exception+0x128/0x250
[c000000015c5fe10] [c00000000000b4d4] system_call_common+0xf4/0x258
--- interrupt: c00 at 0x3fff890b8e8c
NIP:  00003fff890b8e8c LR: 00003fff89323150 CTR: 0000000000000000
REGS: c000000015c5fe80 TRAP: 0c00   Tainted: G                T   (6.1.0-gentoo-PMacG5)
MSR:  900000000200f032 <SF,HV,VEC,EE,PR,FP,ME,IR,DR,RI>  CR: 2842448b  XER: 00000000
IRQMASK: 0 
GPR00: 000000000000000b 00003fffdb20b2c0 00003fff891f7200 000000014a4bc6f0 
GPR04: 000000014a4a1610 000000014a4535c0 000000014a4535c0 000000000000006e 
GPR08: fffffffeb5c1bb40 0000000000000000 0000000000000000 0000000000000000 
GPR12: 0000000000000000 00003fff898ad780 0000000000000000 0000000000000000 
GPR16: 0000000000000000 0000000000000000 00003fffdb20b5c0 000000014a4a0af0 
GPR20: 0000000000000000 0000000000000000 0000000000000001 0000000000000000 
GPR24: 0000000000000000 0000000000000000 00003fffdb20b938 000000014a3e3a48 
GPR28: 000000014a3e3500 000000014a4a1610 000000014a4a1610 0000000000000000 
NIP [00003fff890b8e8c] 0x3fff890b8e8c
LR [00003fff89323150] 0x3fff89323150
--- interrupt: c00
[...]

Created attachment 303425 [details]
kernel .config (6.1.0, PowerMac G5 11,2)

Have not seen this on my G5 and the Talos II since some kernel releases.

Closing as obsolete.