Re: [PATCH 4/5] hw/ppc/ppc4xx_pci: Replace pointless warning by assert()

[Nathan Chancellor <natechancellor@gmail.com>]

On Mon, Jan 11, 2021 at 11:04:25AM +0100, Philippe Mathieu-Daudé wrote:
> +Peter
> 
> On 1/11/21 2:11 AM, Nathan Chancellor wrote:
> > On Tue, Sep 01, 2020 at 12:40:42PM +0200, Philippe Mathieu-Daudé wrote:
> >> We call pci_register_root_bus() to register 4 IRQs with the
> >> ppc4xx_pci_set_irq() handler. As it can only be called with
> >> values in the [0-4[ range, replace the pointless warning by
> >> an assert().
> >>
> >> Signed-off-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
> >> ---
> >>  hw/ppc/ppc4xx_pci.c | 5 +----
> >>  1 file changed, 1 insertion(+), 4 deletions(-)
> >>
> >> diff --git a/hw/ppc/ppc4xx_pci.c b/hw/ppc/ppc4xx_pci.c
> >> index cd3f192a138..503ef46b39a 100644
> >> --- a/hw/ppc/ppc4xx_pci.c
> >> +++ b/hw/ppc/ppc4xx_pci.c
> >> @@ -256,10 +256,7 @@ static void ppc4xx_pci_set_irq(void *opaque, int irq_num, int level)
> >>      qemu_irq *pci_irqs = opaque;
> >>  
> >>      trace_ppc4xx_pci_set_irq(irq_num);
> >> -    if (irq_num < 0) {
> >> -        fprintf(stderr, "%s: PCI irq %d\n", __func__, irq_num);
> >> -        return;
> >> -    }
> >> +    assert(irq_num >= 0);
> >>      qemu_set_irq(pci_irqs[irq_num], level);
> >>  }
> >>  
> >> -- 
> >> 2.26.2
> >>
> >>
> > 
> > Hopefully reporting this here is okay, I find Launchpad hard to use but
> > I can file it there if need be.
> > 
> > The assertion added by this patch triggers while trying to boot a
> > ppc44x_defconfig Linux kernel:
> > 
> > $ qemu-system-ppc \
> >     -machine bamboo \
> >     -no-reboot \
> >     -append console=ttyS0 \
> >     -display none \
> >     -kernel uImage \
> >     -m 128m \
> >     -nodefaults \
> >     -serial mon:stdio
> > Linux version 5.11.0-rc3 (nathan@ubuntu-m3-large-x86) (powerpc-linux-gcc (GCC) 10.2.0, GNU ld (GNU Binutils) 2.35) #1 Sun Jan 10 15:52:24 MST 2021
> > Using PowerPC 44x Platform machine description
> > ioremap() called early from find_legacy_serial_ports+0x64c/0x794. Use early_ioremap() instead
> ...
> > PCI: Probing PCI hardware
> > PCI host bridge to bus 0000:00
> > pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
> > pci_bus 0000:00: root bus resource [mem 0xa0000000-0xbfffffff]
> > pci_bus 0000:00: root bus resource [bus 00-ff]
> > pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to ff
> > pci 0000:00:00.0: [1014:027f] type 00 class 0x068000
> > qemu-system-ppc: ../hw/ppc/ppc4xx_pci.c:259: ppc4xx_pci_set_irq: Assertion `irq_num >= 0' failed.
> > 
> > On v5.2.0, it looks like a higher assertion triggers, added by
> > commit 459ca8bfa4 ("pci: Assert irqnum is between 0 and bus->nirqs in
> > pci_bus_change_irq_level").
> > 
> > qemu-system-ppc: ../hw/pci/pci.c:253: pci_bus_change_irq_level: Assertion `irq_num >= 0' failed.
> 
> Running with '-trace ppc4xx_pci\*':
> 
> 1275265@1610357661.994462:ppc4xx_pci_map_irq devfn 0x0 irq 0 -> 0
> 1275265@1610357661.994480:ppc4xx_pci_set_irq PCI irq -1
> 
> (gdb) bt
> #0  0x00007fc70a8a19e5 in raise () at /lib64/libc.so.6
> #1  0x00007fc70a88a895 in abort () at /lib64/libc.so.6
> #2  0x00007fc70a88a769 in _nl_load_domain.cold () at /lib64/libc.so.6
> #3  0x00007fc70a899e76 in annobin_assert.c_end () at /lib64/libc.so.6
> #4  0x0000560953c2bfe0 in ppc4xx_pci_set_irq (opaque=0x560955dcf9a0,
> irq_num=-1, level=0) at hw/ppc/ppc4xx_pci.c:259
> #5  0x0000560953a20474 in pci_change_irq_level (pci_dev=0x560955dd0e40,
> irq_num=-1, change=0) at hw/pci/pci.c:262
> #6  0x0000560953a1d028 in pci_update_irq_disabled (d=0x560955dd0e40,
> was_irq_disabled=0) at hw/pci/pci.c:1375
> #7  0x0000560953a1ccb3 in pci_default_write_config (d=0x560955dd0e40,
> addr=4, val_in=1030, l=2) at hw/pci/pci.c:1415
> #8  0x0000560953978977 in pci_host_config_write_common
> (pci_dev=0x560955dd0e40, addr=4, limit=256, val=1030, len=2) at
> hw/pci/pci_host.c:83
> #9  0x0000560953978cb9 in pci_data_write (s=0x560955dd0210,
> addr=2147483652, val=1030, len=2) at hw/pci/pci_host.c:120
> #10 0x0000560953978eeb in pci_host_data_write (opaque=0x560955dcf350,
> addr=0, val=1030, len=2) at hw/pci/pci_host.c:167
> 
> How can irq be -1? pci_update_irq_disabled() hasn't been updated
> since commit a7b15a5cc626 (2009-12-23):
> 
> 1368 static void pci_update_irq_disabled(PCIDevice *d, int was_irq_disabled)
> 1369 {
> 1370     int i, disabled = pci_irq_disabled(d);
> 1371     if (disabled == was_irq_disabled)
> 1372         return;
> 1373     for (i = 0; i < PCI_NUM_PINS; ++i) {
> 1374         int state = pci_irq_state(d, i);
> 1375         pci_change_irq_level(d, i, disabled ? -state : state);
> 1376     }
> 1377 }
> 
> Let's rebuild using --enable-sanitizers to check an overflow occured:
> 
> 1286013@1610358549.342593:ppc4xx_pci_map_irq devfn 0x0 irq 0 -> 0
> =================================================================
> ==1286011==ERROR: AddressSanitizer: heap-buffer-overflow on address
> 0x60200004f78c at pc 0x55b6d738454c bp 0x7f779b9f7810 sp 0x7f779b9f7808
> READ of size 4 at 0x60200004f78c thread T2
>     #0 0x55b6d738454b in pci_change_irq_level hw/pci/pci.c:261:29
>     #1 0x55b6d73763be in pci_update_irq_disabled hw/pci/pci.c:1375:9
>     #2 0x55b6d7374e2d in pci_default_write_config hw/pci/pci.c:1415:9
>     #3 0x55b6d70cb8ec in pci_host_config_write_common hw/pci/pci_host.c:83:5
>     #4 0x55b6d70cc43f in pci_data_write hw/pci/pci_host.c:120:5
>     #5 0x55b6d70ccd43 in pci_host_data_write hw/pci/pci_host.c:167:9
>     #6 0x55b6d8505348 in memory_region_write_accessor softmmu/memory.c:483:5
>     #7 0x55b6d8504c1a in access_with_adjusted_size softmmu/memory.c:544:18
>     #8 0x55b6d8503316 in memory_region_dispatch_write
> softmmu/memory.c:1465:16
>     #9 0x55b6d878ab51 in flatview_write_continue exec.c:3177:23
>     #10 0x55b6d8779046 in flatview_write exec.c:3217:14
>     #11 0x55b6d879d1ab in subpage_write exec.c:2829:12
>     #12 0x55b6d8505af7 in memory_region_write_with_attrs_accessor
> softmmu/memory.c:503:12
>     #13 0x55b6d8504af4 in access_with_adjusted_size softmmu/memory.c:539:18
>     #14 0x55b6d850376e in memory_region_dispatch_write
> softmmu/memory.c:1472:13
>     #15 0x55b6d8485b60 in io_writex accel/tcg/cputlb.c:1121:9
>     #16 0x55b6d845ef8b in store_helper accel/tcg/cputlb.c:2140:13
>     #17 0x55b6d845f558 in helper_le_stw_mmu accel/tcg/cputlb.c:2194:5
>     #18 0x7f77a40c0252  (<unknown module>)
> 
> 0x60200004f78c is located 4 bytes to the left of 16-byte region
> [0x60200004f790,0x60200004f7a0)
> allocated by thread T0 here:
>     #0 0x55b6d6ab9227 in calloc (qemu-system-ppc+0x1a9f227)
>     #1 0x7f77f3ab19b0 in g_malloc0 (/lib64/libglib-2.0.so.0+0x589b0)
>     #2 0x55b6d7370ef0 in pci_register_root_bus hw/pci/pci.c:493:5
>     #3 0x55b6d7dec5de in ppc4xx_pcihost_realize hw/ppc/ppc4xx_pci.c:318:9
>     #4 0x55b6d8a04ffb in device_set_realized hw/core/qdev.c:864:13
>     #5 0x55b6d89309e8 in property_set_bool qom/object.c:2202:5
>     #6 0x55b6d8928f92 in object_property_set qom/object.c:1349:5
>     #7 0x55b6d891aa29 in object_property_set_qobject qom/qom-qobject.c:28:10
>     #8 0x55b6d8929d71 in object_property_set_bool qom/object.c:1416:15
>     #9 0x55b6d89f76fc in qdev_realize hw/core/qdev.c:379:12
>     #10 0x55b6d89f7734 in qdev_realize_and_unref hw/core/qdev.c:386:11
>     #11 0x55b6d7ccc37e in sysbus_realize_and_unref hw/core/sysbus.c:261:12
>     #12 0x55b6d7ccc0a3 in sysbus_create_varargs hw/core/sysbus.c:236:5
>     #13 0x55b6d7dbce60 in bamboo_init hw/ppc/ppc440_bamboo.c:212:11
>     #14 0x55b6d6c3cdae in machine_run_board_init hw/core/machine.c:1144:5
>     #15 0x55b6d86893ee in qemu_init softmmu/vl.c:4355:5
>     #16 0x55b6d6af0f49 in main softmmu/main.c:49:5
>     #17 0x7f77f23bd041 in __libc_start_main (/lib64/libc.so.6+0x27041)
> 
> Thread T2 created by T0 here:
>     #0 0x55b6d6a32bb6 in pthread_create (qemu-system-ppc+0x1a18bb6)
>     #1 0x55b6d92a1df4 in qemu_thread_create util/qemu-thread-posix.c:558:11
>     #2 0x55b6d8807dc5 in qemu_tcg_init_vcpu softmmu/cpus.c:1926:13
>     #3 0x55b6d8807142 in qemu_init_vcpu softmmu/cpus.c:2047:9
>     #4 0x55b6d7e79f88 in ppc_cpu_realize
> target/ppc/translate_init.c.inc:10146:5
>     #5 0x55b6d8a04ffb in device_set_realized hw/core/qdev.c:864:13
>     #6 0x55b6d89309e8 in property_set_bool qom/object.c:2202:5
>     #7 0x55b6d8928f92 in object_property_set qom/object.c:1349:5
>     #8 0x55b6d891aa29 in object_property_set_qobject qom/qom-qobject.c:28:10
>     #9 0x55b6d8929d71 in object_property_set_bool qom/object.c:1416:15
>     #10 0x55b6d89f76fc in qdev_realize hw/core/qdev.c:379:12
>     #11 0x55b6d724d4db in cpu_create hw/core/cpu.c:62:10
>     #12 0x55b6d7dbc024 in bamboo_init hw/ppc/ppc440_bamboo.c:183:11
>     #13 0x55b6d6c3cdae in machine_run_board_init hw/core/machine.c:1144:5
>     #14 0x55b6d86893ee in qemu_init softmmu/vl.c:4355:5
>     #15 0x55b6d6af0f49 in main softmmu/main.c:49:5
>     #16 0x7f77f23bd041 in __libc_start_main (/lib64/libc.so.6+0x27041)
> 
> SUMMARY: AddressSanitizer: heap-buffer-overflow hw/pci/pci.c:261:29 in
> pci_change_irq_level
> Shadow bytes around the buggy address:
>   0x0c0480001ea0: fa fa fd fd fa fa fd fd fa fa 00 06 fa fa 00 02
>   0x0c0480001eb0: fa fa fd fd fa fa fd fd fa fa 00 06 fa fa 00 02
>   0x0c0480001ec0: fa fa fd fd fa fa fd fd fa fa 00 06 fa fa 00 02
>   0x0c0480001ed0: fa fa 00 00 fa fa 00 00 fa fa 00 01 fa fa 05 fa
>   0x0c0480001ee0: fa fa 06 fa fa fa fd fd fa fa 06 fa fa fa 00 03
> =>0x0c0480001ef0: fa[fa]00 00 fa fa fd fa fa fa fd fa fa fa fd fa
>   0x0c0480001f00: fa fa fd fa fa fa 00 01 fa fa fd fd fa fa fd fa
>   0x0c0480001f10: fa fa fd fd fa fa 00 02 fa fa fd fa fa fa 00 02
>   0x0c0480001f20: fa fa 05 fa fa fa 07 fa fa fa 00 01 fa fa 07 fa
>   0x0c0480001f30: fa fa 05 fa fa fa 07 fa fa fa fd fd fa fa 00 02
>   0x0c0480001f40: fa fa 05 fa fa fa 07 fa fa fa 00 01 fa fa 07 fa
> Shadow byte legend (one shadow byte represents 8 application bytes):
>   Addressable:           00
>   Partially addressable: 01 02 03 04 05 06 07
>   Heap left redzone:       fa
>   Freed heap region:       fd
>   Stack left redzone:      f1
>   Stack mid redzone:       f2
>   Stack right redzone:     f3
>   Stack after return:      f5
>   Stack use after scope:   f8
>   Global redzone:          f9
>   Global init order:       f6
>   Poisoned by user:        f7
>   Container overflow:      fc
>   Array cookie:            ac
>   Intra object redzone:    bb
>   ASan internal:           fe
>   Left alloca redzone:     ca
>   Right alloca redzone:    cb
>   Shadow gap:              cc
> ==1286011==ABORTING
> 
> I see this sysbus_create_varargs() call in bamboo_init()
> has recently been updated by Peter in commit 0270d74ef88
> ("hw/ppc/ppc440_bamboo: Drop use of ppcuic_init()").
> 
> Running with current master (7b09f127738) the assert is
> not reached:
> 
> Linux version 5.11.0-rc3 (nathan@ubuntu-m3-large-x86) (powerpc-linux-gcc
> (GCC) 10.2.0, GNU ld (GNU Binutils) 2.35) #1 Sun Jan 10 15:52:24 MST 2021
> Using PowerPC 44x Platform machine description
> ioremap() called early from find_legacy_serial_ports+0x64c/0x794. Use
> early_ioremap() instead
> printk: bootconsole [udbg0] enabled
> -----------------------------------------------------
> phys_mem_size     = 0x8000000
> dcache_bsize      = 0x20
> icache_bsize      = 0x20
> cpu_features      = 0x0000000000000100
>   possible        = 0x0000000040000100
>   always          = 0x0000000000000100
> cpu_user_features = 0x8c008000 0x00000000
> mmu_features      = 0x00000008
> -----------------------------------------------------
> Zone ranges:
>   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
> Movable zone start for each node
> Early memory node ranges
>   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
> Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
> MMU: Allocated 1088 bytes of context maps for 255 contexts
> Built 1 zonelists, mobility grouping on.  Total pages: 32448
> Kernel command line: console=ttyS0
> Dentry cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
> Inode-cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
> mem auto-init: stack:off, heap alloc:off, heap free:off
> Memory: 122712K/131072K available (5040K kernel code, 236K rwdata, 1260K
> rodata, 200K init, 134K bss, 8360K reserved, 0K cma-reserved)
> Kernel virtual memory layout:
>   * 0xffbdf000..0xfffff000  : fixmap
>   * 0xffbdd000..0xffbdf000  : early ioremap
>   * 0xd1000000..0xffbdd000  : vmalloc & ioremap
> SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
> NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
> Oops: Exception in kernel mode, sig: 4 [#1]
> BE PAGE_SIZE=4K PowerPC 44x Platform
> Modules linked in:
> CPU: 0 PID: 0 Comm: swapper Not tainted 5.11.0-rc3 #1
> NIP:  c0019e58 LR: c062e3a0 CTR: c0019e58
> REGS: c067fe90 TRAP: 0700   Not tainted  (5.11.0-rc3)
> MSR:  000a1000 <CE,ME>  CR: 84000224  XER: 20000000
> 
> GPR00: c062e370 c067ff50 c065c300 c0019e58 00000000 c0019238 c067fde0
> c065c300
> GPR08: 00000000 00000000 c066fca4 00000066 84000222 00000000 00000000
> 00000000
> GPR16: 00000000 00000000 00000000 00000000 00000000 00000000 c0000010
> 00000000
> GPR24: c0651594 c0651594 c0690000 c7ffe080 c0690000 c05c6f64 c0680000
> c0802100
> NIP [c0019e58] __mtdcr_table+0xc20/0x3ff8
> LR [c062e3a0] uic_init_one+0x13c/0x214
> Call Trace:
> [c067ff50] [c062e370] uic_init_one+0x10c/0x214 (unreliable)
> [c067ff80] [c062e4f8] uic_init_tree+0x80/0x174
> [c067ffb0] [c0627af8] start_kernel+0x33c/0x508
> [c067fff0] [c0000044] _start+0x44/0x88
> Instruction dump:
> 7c9f2b86 4e800020 7c603286 4e800020 7c803386 4e800020 7c613286 4e800020
> 7c813386 4e800020 7c623286 4e800020 <7c823386> 4e800020 7c633286 4e800020
> random: get_random_bytes called from oops_exit+0x44/0x84 with crng_init=0
> ---[ end trace 0000000000000000 ]---
> 
> Kernel panic - not syncing: Attempted to kill the idle task!
> Rebooting in 180 seconds..
> 
> I suppose we can end this thread as NOTABUG.
> 
> Thanks for testing and your report,
> 
> Phil.

For what it's worth, I initially ran into this assertion on v5.2.0,
which does not include Peter's commit since it is only in master (and
I reported a problem with separately). If they are indeed related then
fair enough :) thanks for taking a look.

Cheers,
Nathan