From nobody Fri Sep 22 11:00:56 2023 X-Original-To: freebsd-drivers@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4RsTpd3nfbz4thv8 for ; Fri, 22 Sep 2023 11:01:13 +0000 (UTC) (envelope-from john@sanren.ac.za) Received: from mail-pg1-x533.google.com (mail-pg1-x533.google.com [IPv6:2607:f8b0:4864:20::533]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1D4" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4RsTpb3dFmz4swf for ; Fri, 22 Sep 2023 11:01:11 +0000 (UTC) (envelope-from john@sanren.ac.za) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=sanren-ac-za.20230601.gappssmtp.com header.s=20230601 header.b=g2bIFEgg; spf=pass (mx1.freebsd.org: domain of john@sanren.ac.za designates 2607:f8b0:4864:20::533 as permitted sender) smtp.mailfrom=john@sanren.ac.za; dmarc=none Received: by mail-pg1-x533.google.com with SMTP id 41be03b00d2f7-578d78ffdbcso1351345a12.2 for ; Fri, 22 Sep 2023 04:01:10 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=sanren-ac-za.20230601.gappssmtp.com; s=20230601; t=1695380468; x=1695985268; darn=freebsd.org; h=to:subject:message-id:date:from:mime-version:from:to:cc:subject :date:message-id:reply-to; bh=t1N6syaNDubDDT+qEB02C++X0VZsS5YiqLlWAGHxvVA=; b=g2bIFEggbmTlrhQKxK0WkhoohZGthMi/+rDxUPKzKFApjyxsdC47vU92xbSHAfLz7h ymZJcx30sZ14YBiwd2adt/qF8cov2wfHYWs4KBxjkkUttbrVW2WXaKojP9qBWWcX1B99 zlkw8xGl2qhwyhle33kIdDFLGr3itVARyqg/0ESpXuPhjTOkf9vu22gCcZr/7hNctmGo INArybYqsAt8YQBRwBZGGux2I4/jIHSfLJlpquFZzPd62XJf0mGyBzh0uGUWAvpJImV9 AXlQJymFBHjUEly2afWKQBl9bS4nC+IxlL3ipswD6+niuxsGcTiQxM6SykX+ohueCb0f COww== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1695380468; x=1695985268; h=to:subject:message-id:date:from:mime-version:x-gm-message-state :from:to:cc:subject:date:message-id:reply-to; bh=t1N6syaNDubDDT+qEB02C++X0VZsS5YiqLlWAGHxvVA=; b=K8O9mEpQvN5sYKhBsmTYMtAufaWiQjQ5tG0PLuIYy9z1b0a0BtRfTeocxstP3fXUg7 vwuYzmnJahEThl+8vMLJ8w5sX78eQB97pRFRTLHzK4qRql66lVggLFgohZ+luJm6xfOF mg/lXTgkZ/WyGtOIlCmzYab7mpG1AsImXF6fG54/wOJT7iPh8yTH15PQ+H8vUzlMYZCS A0VKW5zL0zMo3fpN32RnHYxyAchruYSL0RzFW6Pdlo1AwZFcnox2dNbqRZ+aw0A3IyEb 5isKYWW0XDYkR6qANtaqUP8k/kf+66I1R3vxdLASEm+9YA8/3zGQFaXDRh66GsgtuEcx RigQ== X-Gm-Message-State: AOJu0YxHkhmxVnjdn7Y2uYvy1LW7OO+SWljmLmJsbf7AvEksn10B/eHO vqEf6Waq2R5p0DvXqdZdxRkTiTwt8U8lsKzWSLENJUzrytmFcLEX7to= X-Google-Smtp-Source: AGHT+IF4j3VCiAnRWc8YNkaOzYdMeT9kiMY63+zDfo65sDUp/ELXxxeR2YoxFYwUpCbgKeKzzRCMDDJbvz/K68A4if4= X-Received: by 2002:a17:90b:38d2:b0:268:352c:9d13 with SMTP id nn18-20020a17090b38d200b00268352c9d13mr7898253pjb.0.1695380468059; Fri, 22 Sep 2023 04:01:08 -0700 (PDT) List-Id: Writing device drivers for FreeBSD List-Archive: https://lists.freebsd.org/archives/freebsd-drivers List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-drivers@freebsd.org MIME-Version: 1.0 From: John Hay Date: Fri, 22 Sep 2023 13:00:56 +0200 Message-ID: Subject: debugging a msi interrupt panic To: freebsd-drivers@freebsd.org Content-Type: multipart/alternative; boundary="0000000000008eedcc0605f086ba" X-Spamd-Bar: --- X-Spamd-Result: default: False [-3.49 / 15.00]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_SHORT(-0.99)[-0.986]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36]; R_DKIM_ALLOW(-0.20)[sanren-ac-za.20230601.gappssmtp.com:s=20230601]; MIME_GOOD(-0.10)[multipart/alternative,text/plain]; RCVD_IN_DNSWL_NONE(0.00)[2607:f8b0:4864:20::533:from]; FROM_EQ_ENVFROM(0.00)[]; MLMMJ_DEST(0.00)[freebsd-drivers@freebsd.org]; RCVD_COUNT_ONE(0.00)[1]; MIME_TRACE(0.00)[0:+,1:+,2:~]; DKIM_TRACE(0.00)[sanren-ac-za.20230601.gappssmtp.com:+]; ARC_NA(0.00)[]; RCVD_TLS_LAST(0.00)[]; TO_MATCH_ENVRCPT_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; DMARC_NA(0.00)[sanren.ac.za]; PREVIOUSLY_DELIVERED(0.00)[freebsd-drivers@freebsd.org]; RCPT_COUNT_ONE(0.00)[1]; TO_DN_NONE(0.00)[]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US] X-Rspamd-Queue-Id: 4RsTpb3dFmz4swf --0000000000008eedcc0605f086ba Content-Type: text/plain; charset="UTF-8" Hi, How do one debug msi interrupts on FreeBSD when writing a device driver? I'm writing a driver for a OCP TimeCard. The card has several different functions, each "tied" to a specific msi interrupt. So it would be useful to use multiple msi interrupts. The PCIe functionality is a Xilinx AXI PCIe blob, with 32 MSI interrupts. It does not have MSI-X capability. # pciconf -lbc none1@pci0:1:0:0: none0@pci0:1:0:0: class=0x058000 rev=0x00 hdr=0x00 vendor=0x1d9b device=0x0400 subvendor=0x10ee subdevice=0x0007 bar [10] = type Memory, range 32, base 0xf4000000, size 33554432, enabled cap 01[40] = powerspec 3 supports D0 D3 current D0 cap 05[48] = MSI supports 32 messages, 64 bit cap 10[60] = PCI-Express 2 endpoint max data 256(256) NS max read 512 link x1(x1) speed 2.5(2.5) ASPM disabled(L0s) ecap 0003[100] = Serial 1 0000000000000000 Currently in attach, I'm doing the following (error checking removed): pci_enable_busmaster(dev); /* msi irq needs it enabled, at least for the AXI core */ sc->sc_msi = pci_msi_count(dev); pci_alloc_msi(dev, &sc->sc_msi) loop for each function /* currently just a single iteration to get one function working */ port->pp_irid = port->intr_num + 1; /* msi irq no starts at one */ port->pp_ires = bus_alloc_resource_any(dev, SYS_RES_IRQ, &port->pp_irid, RF_ACTIVE | RF_SHAREABLE); bus_setup_intr(dev, port->pp_ires, INTR_TYPE_TTY | INTR_MPSAFE, timecard_intr, NULL, port, &port->p_ihandle) I did define a variable timecard_intr_count that timecard_intr() should increment, but it does not change, so timecard_intr() probably does not get called. Here is the console output of the panic and a show apic and show lapic. The driver is not compiled in, but loaded later manually. pci0: driver added found-> vendor=0x8086, dev=0x1e3a, revid=0x04 domain=0, bus=0, slot=22, func=0 class=07-80-00, hdrtype=0x00, mfdev=1 cmdreg=0x0006, statreg=0x0010, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=16 powerspec 3 supports D0 D3 current D0 MSI supports 1 message, 64 bit pci0:0:22:0: reprobing on driver added timecard0: TimeCard Probe Vendor ID : 0x8086 Device ID : 0x1e3a pci1: driver added found-> vendor=0x1d9b, dev=0x0400, revid=0x00 domain=0, bus=1, slot=0, func=0 class=05-80-00, hdrtype=0x00, mfdev=0 cmdreg=0x0002, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) powerspec 3 supports D0 D3 current D0 MSI supports 32 messages, 64 bit pci0:1:0:0: reprobing on driver added timecard0: TimeCard Probe Vendor ID : 0x1d9b Device ID : 0x400 We've got the TimeCard, probe successful! timecard0: TimeCard Probe Vendor ID : 0x1d9b Device ID : 0x400 We've got the TimeCard, probe successful! timecard0: mem 0xf4000000-0xf5ffffff at device 0.0 on pci1 TimeCard Attach for : deviceID : 0x4001d9b Address of timecard_intr_count 0xffffffff8314e400 timecard0: attempting to allocate 32 MSI vectors (32 supported) msi: routing MSI IRQ 38 to local APIC 4 vector 80 msi: routing MSI IRQ 39 to local APIC 4 vector 81 msi: routing MSI IRQ 40 to local APIC 4 vector 82 msi: routing MSI IRQ 41 to local APIC 4 vector 83 msi: routing MSI IRQ 42 to local APIC 4 vector 84 msi: routing MSI IRQ 43 to local APIC 4 vector 85 msi: routing MSI IRQ 44 to local APIC 4 vector 86 msi: routing MSI IRQ 45 to local APIC 4 vector 87 msi: routing MSI IRQ 46 to local APIC 4 vector 88 msi: routing MSI IRQ 47 to local APIC 4 vector 89 msi: routing MSI IRQ 48 to local APIC 4 vector 90 msi: routing MSI IRQ 49 to local APIC 4 vector 91 msi: routing MSI IRQ 50 to local APIC 4 vector 92 msi: routing MSI IRQ 51 to local APIC 4 vector 93 msi: routing MSI IRQ 52 to local APIC 4 vector 94 msi: routing MSI IRQ 53 to local APIC 4 vector 95 msi: routing MSI IRQ 54 to local APIC 4 vector 96 msi: routing MSI IRQ 55 to local APIC 4 vector 97 msi: routing MSI IRQ 56 to local APIC 4 vector 98 msi: routing MSI IRQ 57 to local APIC 4 vector 99 msi: routing MSI IRQ 58 to local APIC 4 vector 100 msi: routing MSI IRQ 59 to local APIC 4 vector 101 msi: routing MSI IRQ 60 to local APIC 4 vector 102 msi: routing MSI IRQ 61 to local APIC 4 vector 103 msi: routing MSI IRQ 62 to local APIC 4 vector 104 msi: routing MSI IRQ 63 to local APIC 4 vector 105 msi: routing MSI IRQ 64 to local APIC 4 vector 106 msi: routing MSI IRQ 65 to local APIC 4 vector 107 msi: routing MSI IRQ 66 to local APIC 4 vector 108 msi: routing MSI IRQ 67 to local APIC 4 vector 109 msi: routing MSI IRQ 68 to local APIC 4 vector 110 msi: routing MSI IRQ 69 to local APIC 4 vector 111 timecard0: using IRQs 38-69 for MSI TimeCard msi 32 rman iomem start f4000000, end f5ffffff, size 2000000 timecard_corelist_read did not find list, using fb list 1 nports 1 Start with uart 0 0 irq 41, irid 4 Fatal trap 30: reserved (unknown) fault while in kernel mode cpuid = 2; apic id = 04 port irq rid 4 instruction pointer = 0x20:0xffffffff804dda2d stack pointer = 0x28:0xfffffe001b1d8de0 TimeCard device loaded. pci2: driver added pci3: driver added pci4: driver added frame pointer = 0x28:0xfffffe001b1d8e10 code segment = base 0x0, limit 0xfffff, type 0x1b pci5: driver added = DPL 0, pres 1, long 1, def32 0, gran 1 processor eflags = interrupt enabled, IOPL = 0 current process = 11 (idle: cpu2) trap number = 30 panic: reserved (unknown) fault cpuid = 2 time = 1695375919 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe001b1d8c00 vpanic() at vpanic+0x151/frame 0xfffffe001b1d8c50 panic() at panic+0x43/frame 0xfffffe001b1d8cb0 trap_fatal() at trap_fatal+0x387/frame 0xfffffe001b1d8d10 calltrap() at calltrap+0x8/frame 0xfffffe001b1d8d10 --- trap 0x1e, rip = 0xffffffff804dda2d, rsp = 0xfffffe001b1d8de0, rbp = 0xfffffe001b1d8e10 --- acpi_cpu_idle() at acpi_cpu_idle+0x28d/frame 0xfffffe001b1d8e10 cpu_idle_acpi() at cpu_idle_acpi+0x4d/frame 0xfffffe001b1d8e30 cpu_idle() at cpu_idle+0xac/frame 0xfffffe001b1d8e50 sched_idletd() at sched_idletd+0x4b1/frame 0xfffffe001b1d8ef0 fork_exit() at fork_exit+0x80/frame 0xfffffe001b1d8f30 fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe001b1d8f30 --- trap 0xe0c2545f, rip = 0x8f4a0c76246ffed9, rsp = 0x670c1cf091ea5e5b, rbp = 0x57639a151e2b2985 --- KDB: enter: panic [ thread pid 11 tid 100005 ] Stopped at kdb_enter+0x37: movq $0,0x129840e(%rip) db> x/wx timecard_intr_count timecard_intr_count: 0 db> show apic Interrupts bound to lapic 0 vec 0x30 -> IRQ 9 vec 0x31 -> IRQ 28 vec 0x32 -> IRQ 31 vec 0x33 -> IRQ 24 vec 0x34 -> IRQ 29 vec 0x35 -> IRQ 30 vec 0x36 -> IRQ 8 vec 0x37 -> IRQ 16 vec 0x38 -> IRQ 36 vec 0x39 -> IRQ 1 vec 0xef -> lapic timer Interrupts bound to lapic 2 vec 0x30 -> IRQ 25 vec 0x31 -> IRQ 33 vec 0x32 -> IRQ 23 vec 0x33 -> IRQ 18 vec 0xef -> lapic timer Interrupts bound to lapic 4 vec 0x30 -> IRQ 26 vec 0x31 -> IRQ 0 vec 0x32 -> IRQ 34 vec 0x33 -> IRQ 37 vec 0x50 -> IRQ 38 vec 0x51 -> IRQ 39 vec 0x52 -> IRQ 40 vec 0x53 -> IRQ 41 vec 0x54 -> IRQ 42 vec 0x55 -> IRQ 43 vec 0x56 -> IRQ 44 vec 0x57 -> IRQ 45 vec 0x58 -> IRQ 46 vec 0x59 -> IRQ 47 vec 0x5a -> IRQ 48 vec 0x5b -> IRQ 49 vec 0x5c -> IRQ 50 vec 0x5d -> IRQ 51 vec 0x5e -> IRQ 52 vec 0x5f -> IRQ 53 vec 0x60 -> IRQ 54 vec 0x61 -> IRQ 55 vec 0x62 -> IRQ 56 vec 0x63 -> IRQ 57 vec 0x64 -> IRQ 58 vec 0x65 -> IRQ 59 vec 0x66 -> IRQ 60 vec 0x67 -> IRQ 61 vec 0x68 -> IRQ 62 vec 0x69 -> IRQ 63 vec 0x6a -> IRQ 64 vec 0x6b -> IRQ 65 vec 0x6c -> IRQ 66 vec 0x6d -> IRQ 67 vec 0x6e -> IRQ 68 vec 0x6f -> IRQ 69 vec 0xef -> lapic timer Interrupts bound to lapic 6 vec 0x30 -> IRQ 27 vec 0x31 -> IRQ 32 vec 0x32 -> IRQ 35 vec 0x33 -> IRQ 4 vec 0xef -> lapic timer db> show lapic lapic ID = 4 version = 1.5 max LVT = 6 SVR = ff (enabled) TPR = 00 In-service Interrupts: isr2: 43 TMR Interrupts: IRR Interrupts: irr1: 32 33 irr2: 43 irr7: ef db> Regards John --0000000000008eedcc0605f086ba Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Hi,

How do one debug msi int= errupts on FreeBSD when writing a device driver?

I= 'm writing a driver for a OCP TimeCard. The card has several different = functions, each "tied" to a specific msi interrupt. So it would b= e useful to use multiple msi interrupts. The PCIe functionality is a Xilinx= AXI PCIe blob, with 32 MSI interrupts. It does not have MSI-X capability.<= br>

<snip>
# pciconf -lbc none= 1@pci0:1:0:0:
none0@pci0:1:0:0: class=3D0x058000 rev=3D0x00 hdr=3D0x00 v= endor=3D0x1d9b device=3D0x0400 subvendor=3D0x10ee subdevice=3D0x0007
=C2= =A0 =C2=A0 bar =C2=A0 [10] =3D type Memory, range 32, base 0xf4000000, size= 33554432, enabled
=C2=A0 =C2=A0 cap 01[40] =3D powerspec 3 =C2=A0suppor= ts D0 D3 =C2=A0current D0
=C2=A0 =C2=A0 cap 05[48] =3D MSI supports 32 m= essages, 64 bit
=C2=A0 =C2=A0 cap 10[60] =3D PCI-Express 2 endpoint max= data 256(256) NS
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0max read 512
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0link x1(x1) speed 2.5(2.5) ASPM disabled(L0s)
=C2=A0 =C2=A0= ecap 0003[100] =3D Serial 1 0000000000000000
</snip>

Currently in attach, I'm doing the followin= g (error checking removed):

<snip>
=
pci_enable_busmaster(dev); /* msi irq needs it enabled, at least for t= he AXI core */
sc->sc_msi =3D pci_msi_count(dev);
pci_alloc_msi(dev, &sc->sc_msi)
loop for each function /= * currently just a single iteration to get one function working */
=C2=A0=C2=A0 port->pp_irid =3D port->intr_num + 1; /* msi irq n= o starts at one */
=C2=A0=C2=A0 port->pp_ires =3D bus_allo= c_resource_any(dev, SYS_RES_IRQ, &port->pp_irid, RF_ACTIVE | RF_SHAR= EABLE);
=C2=A0=C2=A0 bus_setup_intr(dev, port->pp_ires, INTR_T= YPE_TTY | INTR_MPSAFE, timecard_intr, NULL, port, &port->p_ihandle)<= /div>
</snip>

I did define a variable ti= mecard_intr_count that timecard_intr() should increment, but it does not ch= ange, so timecard_intr() probably does not get called.

=
Here is the console output of the panic and a show apic and show lapic= . The driver is not compiled in, but loaded later manually.

<= /div>
<snip>
pci0: driver added
found-> vendor=3D= 0x8086, dev=3D0x1e3a, revid=3D0x04
=C2=A0 =C2=A0 =C2=A0 =C2=A0 domain=3D= 0, bus=3D0, slot=3D22, func=3D0
=C2=A0 =C2=A0 =C2=A0 =C2=A0 class=3D07-8= 0-00, hdrtype=3D0x00, mfdev=3D1
=C2=A0 =C2=A0 =C2=A0 =C2=A0 cmdreg=3D0x0= 006, statreg=3D0x0010, cachelnsz=3D0 (dwords)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 lattimer=3D0x00 (0 ns), mingnt=3D0x00 (0 ns), maxlat=3D0x00 (0 ns)
= =C2=A0 =C2=A0 =C2=A0 =C2=A0 intpin=3Da, irq=3D16
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 powerspec 3 =C2=A0supports D0 D3 =C2=A0current D0
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 MSI supports 1 message, 64 bit
pci0:0:22:0: reprobing on d= river added
timecard0: TimeCard Probe
Vendor ID : 0x8086
Device ID= : 0x1e3a
pci1: driver added
found-> vendor=3D0x1d9b, dev=3D0x0400= , revid=3D0x00
=C2=A0 =C2=A0 =C2=A0 =C2=A0 domain=3D0, bus=3D1, slot=3D0= , func=3D0
=C2=A0 =C2=A0 =C2=A0 =C2=A0 class=3D05-80-00, hdrtype=3D0x00,= mfdev=3D0
=C2=A0 =C2=A0 =C2=A0 =C2=A0 cmdreg=3D0x0002, statreg=3D0x0010= , cachelnsz=3D16 (dwords)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 lattimer=3D0x00 (0= ns), mingnt=3D0x00 (0 ns), maxlat=3D0x00 (0 ns)
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 powerspec 3 =C2=A0supports D0 D3 =C2=A0current D0
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 MSI supports 32 messages, 64 bit
pci0:1:0:0: reprobing on = driver added
timecard0: TimeCard Probe
Vendor ID : 0x1d9b
Device I= D : 0x400
We've got the TimeCard, probe successful!
timecard0: Ti= meCard Probe
Vendor ID : 0x1d9b
Device ID : 0x400
We've got th= e TimeCard, probe successful!
timecard0: <TimeCard> mem 0xf4000000= -0xf5ffffff at device 0.0 on pci1
TimeCard Attach for : deviceID : 0x400= 1d9b
Address of timecard_intr_count 0xffffffff8314e400
timecard0: att= empting to allocate 32 MSI vectors (32 supported)
msi: routing MSI IRQ 3= 8 to local APIC 4 vector 80
msi: routing MSI IRQ 39 to local APIC 4 vect= or 81
msi: routing MSI IRQ 40 to local APIC 4 vector 82
msi: routing = MSI IRQ 41 to local APIC 4 vector 83
msi: routing MSI IRQ 42 to local AP= IC 4 vector 84
msi: routing MSI IRQ 43 to local APIC 4 vector 85
msi:= routing MSI IRQ 44 to local APIC 4 vector 86
msi: routing MSI IRQ 45 to= local APIC 4 vector 87
msi: routing MSI IRQ 46 to local APIC 4 vector 8= 8
msi: routing MSI IRQ 47 to local APIC 4 vector 89
msi: routing MSI = IRQ 48 to local APIC 4 vector 90
msi: routing MSI IRQ 49 to local APIC 4= vector 91
msi: routing MSI IRQ 50 to local APIC 4 vector 92
msi: rou= ting MSI IRQ 51 to local APIC 4 vector 93
msi: routing MSI IRQ 52 to loc= al APIC 4 vector 94
msi: routing MSI IRQ 53 to local APIC 4 vector 95msi: routing MSI IRQ 54 to local APIC 4 vector 96
msi: routing MSI IRQ = 55 to local APIC 4 vector 97
msi: routing MSI IRQ 56 to local APIC 4 vec= tor 98
msi: routing MSI IRQ 57 to local APIC 4 vector 99
msi: routing= MSI IRQ 58 to local APIC 4 vector 100
msi: routing MSI IRQ 59 to local = APIC 4 vector 101
msi: routing MSI IRQ 60 to local APIC 4 vector 102
= msi: routing MSI IRQ 61 to local APIC 4 vector 103
msi: routing MSI IRQ = 62 to local APIC 4 vector 104
msi: routing MSI IRQ 63 to local APIC 4 ve= ctor 105
msi: routing MSI IRQ 64 to local APIC 4 vector 106
msi: rout= ing MSI IRQ 65 to local APIC 4 vector 107
msi: routing MSI IRQ 66 to loc= al APIC 4 vector 108
msi: routing MSI IRQ 67 to local APIC 4 vector 109<= br>msi: routing MSI IRQ 68 to local APIC 4 vector 110
msi: routing MSI I= RQ 69 to local APIC 4 vector 111
timecard0: using IRQs 38-69 for MSI
= TimeCard msi 32
rman iomem start f4000000, end f5ffffff, size 2000000timecard_corelist_read did not find list, using fb list 1
nports 1
S= tart with uart 0 0
irq 41, irid 4


Fatal trap 30: reserved (un= known) fault while in kernel mode
cpuid =3D 2; apic id =3D 04
port ir= q rid 4
instruction pointer =C2=A0 =C2=A0 =3D 0x20:0xffffffff804dda2dstack pointer =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =3D 0x28:0xfffffe001b1d8d= e0
TimeCard device loaded.
pci2: driver added
pci3: driver addedpci4: driver added
frame pointer =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =3D 0x28:0xfffffe001b1d8e10
code segment =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0=3D base 0x0, limit 0xfffff, type 0x1b
pci5: driver added
= =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =3D DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags = =C2=A0 =C2=A0 =C2=A0 =C2=A0=3D interrupt enabled, IOPL =3D 0
current pro= cess =C2=A0 =C2=A0 =C2=A0 =C2=A0 =3D 11 (idle: cpu2)
trap number =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =3D 30
panic: reserved (unknown) faul= t
cpuid =3D 2
time =3D 1695375919
KDB: stack backtrace:
db_trac= e_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe001b1d8c00
= vpanic() at vpanic+0x151/frame 0xfffffe001b1d8c50
panic() at panic+0x43/= frame 0xfffffe001b1d8cb0
trap_fatal() at trap_fatal+0x387/frame 0xfffffe= 001b1d8d10
calltrap() at calltrap+0x8/frame 0xfffffe001b1d8d10
--- tr= ap 0x1e, rip =3D 0xffffffff804dda2d, rsp =3D 0xfffffe001b1d8de0, rbp =3D 0x= fffffe001b1d8e10 ---
acpi_cpu_idle() at acpi_cpu_idle+0x28d/frame 0xffff= fe001b1d8e10
cpu_idle_acpi() at cpu_idle_acpi+0x4d/frame 0xfffffe001b1d8= e30
cpu_idle() at cpu_idle+0xac/frame 0xfffffe001b1d8e50
sched_idletd= () at sched_idletd+0x4b1/frame 0xfffffe001b1d8ef0
fork_exit() at fork_ex= it+0x80/frame 0xfffffe001b1d8f30
fork_trampoline() at fork_trampoline+0x= e/frame 0xfffffe001b1d8f30
--- trap 0xe0c2545f, rip =3D 0x8f4a0c76246ffe= d9, rsp =3D 0x670c1cf091ea5e5b, rbp =3D 0x57639a151e2b2985 ---
KDB: ente= r: panic
[ thread pid 11 tid 100005 ]
Stopped at =C2=A0 =C2=A0 =C2=A0= kdb_enter+0x37: movq =C2=A0 =C2=A0$0,0x129840e(%rip)
db> x/wx timecar= d_intr_count
timecard_intr_count: =C2=A0 =C2=A00
db> show apic
= Interrupts bound to lapic 0
vec 0x30 -> IRQ 9
vec 0x31 -> IRQ 2= 8
vec 0x32 -> IRQ 31
vec 0x33 -> IRQ 24
vec 0x34 -> IRQ 2= 9
vec 0x35 -> IRQ 30
vec 0x36 -> IRQ 8
vec 0x37 -> IRQ 16=
vec 0x38 -> IRQ 36
vec 0x39 -> IRQ 1
vec 0xef -> lapic t= imer
Interrupts bound to lapic 2
vec 0x30 -> IRQ 25
vec 0x31 -&= gt; IRQ 33
vec 0x32 -> IRQ 23
vec 0x33 -> IRQ 18
vec 0xef -&= gt; lapic timer
Interrupts bound to lapic 4
vec 0x30 -> IRQ 26
= vec 0x31 -> IRQ 0
vec 0x32 -> IRQ 34
vec 0x33 -> IRQ 37
v= ec 0x50 -> IRQ 38
vec 0x51 -> IRQ 39
vec 0x52 -> IRQ 40
v= ec 0x53 -> IRQ 41
vec 0x54 -> IRQ 42
vec 0x55 -> IRQ 43
v= ec 0x56 -> IRQ 44
vec 0x57 -> IRQ 45
vec 0x58 -> IRQ 46
v= ec 0x59 -> IRQ 47
vec 0x5a -> IRQ 48
vec 0x5b -> IRQ 49
v= ec 0x5c -> IRQ 50
vec 0x5d -> IRQ 51
vec 0x5e -> IRQ 52
v= ec 0x5f -> IRQ 53
vec 0x60 -> IRQ 54
vec 0x61 -> IRQ 55
v= ec 0x62 -> IRQ 56
vec 0x63 -> IRQ 57
vec 0x64 -> IRQ 58
v= ec 0x65 -> IRQ 59
vec 0x66 -> IRQ 60
vec 0x67 -> IRQ 61
v= ec 0x68 -> IRQ 62
vec 0x69 -> IRQ 63
vec 0x6a -> IRQ 64
v= ec 0x6b -> IRQ 65
vec 0x6c -> IRQ 66
vec 0x6d -> IRQ 67
v= ec 0x6e -> IRQ 68
vec 0x6f -> IRQ 69
vec 0xef -> lapic timer=
Interrupts bound to lapic 6
vec 0x30 -> IRQ 27
vec 0x31 -> = IRQ 32
vec 0x32 -> IRQ 35
vec 0x33 -> IRQ 4
vec 0xef -> l= apic timer
db> show lapic
lapic ID =3D 4
version =C2=A0=3D 1.5<= br>max LVT =C2=A0=3D 6
SVR =C2=A0 =C2=A0 =C2=A0=3D ff (enabled)
TPR = =C2=A0 =C2=A0 =C2=A0=3D 00
In-service Interrupts:
isr2: 43
TMR Int= errupts:
IRR Interrupts:
irr1: 32 33
irr2: 43
irr7: ef
db>= ;
</snip>

Regards
<= br>
John

--0000000000008eedcc0605f086ba-- From nobody Mon Sep 25 08:30:16 2023 X-Original-To: freebsd-drivers@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4RvGKN2ZH5z4vF2v for ; Mon, 25 Sep 2023 08:30:32 +0000 (UTC) (envelope-from john@sanren.ac.za) Received: from mail-pj1-x1030.google.com (mail-pj1-x1030.google.com [IPv6:2607:f8b0:4864:20::1030]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1D4" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4RvGKM1nNYz4Wld for ; Mon, 25 Sep 2023 08:30:30 +0000 (UTC) (envelope-from john@sanren.ac.za) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=sanren-ac-za.20230601.gappssmtp.com header.s=20230601 header.b=c7OFa1lw; spf=pass (mx1.freebsd.org: domain of john@sanren.ac.za designates 2607:f8b0:4864:20::1030 as permitted sender) smtp.mailfrom=john@sanren.ac.za; dmarc=none Received: by mail-pj1-x1030.google.com with SMTP id 98e67ed59e1d1-27752a1e184so1197138a91.3 for ; Mon, 25 Sep 2023 01:30:30 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=sanren-ac-za.20230601.gappssmtp.com; s=20230601; t=1695630628; x=1696235428; darn=freebsd.org; h=to:subject:message-id:date:from:in-reply-to:references:mime-version :from:to:cc:subject:date:message-id:reply-to; bh=w6fz26obuukWif+eVOJLR0atGsZ1zUqHukJt2XALllI=; b=c7OFa1lwLY31Q8/At8ETM/2PWhw/DZ7ELjNsDXy3OCxwlVt6f9pKFb1iX8tIeFd3/n +Xgv9xSgCpj0MEKeENPwFWMaiyH128eyDAXjtKhvjtDAZ+LXJEPOUdu0jgNJH2N0L1Lo nXCTn8XN20yZusCxBmoGqjTkl96GGcExE3CU1Kpqvzbr01cgis0oqCPXZDIRzT/vMiPb tKDJ/N+krohkCB4ufevhWMyVvVeWEUxua90EU+s+11d1dm+ihjWd7hx8Qv1iMtWldsru 2NsqCHF3X6bsXjge7KQGBII/H6F01pXiml7c0Ff8OiuSPZqSt/D5Mq+cCYAucZ2C2BOp +VoQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1695630628; x=1696235428; h=to:subject:message-id:date:from:in-reply-to:references:mime-version :x-gm-message-state:from:to:cc:subject:date:message-id:reply-to; bh=w6fz26obuukWif+eVOJLR0atGsZ1zUqHukJt2XALllI=; b=eTUOr98k4O+ZnSGiyZBtX7N8V0qVbT15YKYmRV7SmBiFg+VApiw+wFYWKdolr3IOwW YWj/K0epW21YW9UHUFlj4ly/cpOfWN1Vh6+UkoAMy19hUtq11KJtfoYJjUTKHqlH5/T8 9m78rIa9btLlxzozqO7BhNFTGnb2jz2hBpZRfavaDz1jbpef3MZxUqYbzUpL1RKM0GHo hBv4Vc+8yor61LqQyksuMEp7LJUhEinp0THgRxI717D8eS205JSb4u0ns6BPFAJZNUXD byNK8YO8G6IJx1qgymJ73vtAIJMB5RB0ir1hrNM3jV0acHiIgaVpGmwWRtkYSKo7mWro p4sA== X-Gm-Message-State: AOJu0Yy4P6CA+9txeYKr4vST8ZoQMajN32luu0iPqFWQ07b5dzSjd7OR 5WyMK5wVw0uHnei5wetER6mspT7cSety9Lw5mwrMyiir6pCN8yZdw18= X-Google-Smtp-Source: AGHT+IElwaxPhbDO2ZrNuGbBXNtrj9b2bza56GmJQ084Ks1LdxxLhxwOUffajKWJVf8wBappPvsuQIxYXxv6Bx0XOWs= X-Received: by 2002:a17:90b:2397:b0:277:37fc:6e85 with SMTP id mr23-20020a17090b239700b0027737fc6e85mr3885412pjb.0.1695630628345; Mon, 25 Sep 2023 01:30:28 -0700 (PDT) List-Id: Writing device drivers for FreeBSD List-Archive: https://lists.freebsd.org/archives/freebsd-drivers List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-drivers@freebsd.org MIME-Version: 1.0 References: In-Reply-To: From: John Hay Date: Mon, 25 Sep 2023 10:30:16 +0200 Message-ID: Subject: Re: debugging a msi interrupt panic To: freebsd-drivers@freebsd.org Content-Type: multipart/alternative; boundary="00000000000045eb7206062ac5dc" X-Spamd-Bar: --- X-Spamd-Result: default: False [-3.50 / 15.00]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_SHORT(-1.00)[-0.999]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36]; R_DKIM_ALLOW(-0.20)[sanren-ac-za.20230601.gappssmtp.com:s=20230601]; MIME_GOOD(-0.10)[multipart/alternative,text/plain]; RCVD_IN_DNSWL_NONE(0.00)[2607:f8b0:4864:20::1030:from]; FROM_EQ_ENVFROM(0.00)[]; MLMMJ_DEST(0.00)[freebsd-drivers@freebsd.org]; RCVD_COUNT_ONE(0.00)[1]; MIME_TRACE(0.00)[0:+,1:+,2:~]; DKIM_TRACE(0.00)[sanren-ac-za.20230601.gappssmtp.com:+]; ARC_NA(0.00)[]; RCVD_TLS_LAST(0.00)[]; TO_MATCH_ENVRCPT_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; DMARC_NA(0.00)[sanren.ac.za]; PREVIOUSLY_DELIVERED(0.00)[freebsd-drivers@freebsd.org]; RCPT_COUNT_ONE(0.00)[1]; TO_DN_NONE(0.00)[]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US] X-Rspamd-Queue-Id: 4RvGKM1nNYz4Wld --00000000000045eb7206062ac5dc Content-Type: text/plain; charset="UTF-8" Hi, I found the cause of the panics and thought I should give feedback here. MSI interrupt vectors have to be aligned to the size of the allocation, which have to be in powers of 2 up to a maximum of 32 vectors. native_apic_alloc_vectors(), which is used by pci_alloc_msi(), does not properly align the vectors that it allocates. It does an aligned check, but then after that adds APIC_IO_INTS, which is 48, and so the alignment is lost. So allocating smaller numbers of vectors would work because 48 is a multiple of 16. If you allocate 32 MSI interrupts, the pcie card just ignores the bottom 5 bits of the vector that was written to its MSI_DATA register, so in my case where native_apic_alloc_vectors() allocated a base vector of 0x50, the card ignores bit 4 and generates interrupt vectors from 0x40 to 0x5f. I have opened a bug report about it: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=274074 Regards John On Fri, 22 Sept 2023 at 13:00, John Hay wrote: > Hi, > > How do one debug msi interrupts on FreeBSD when writing a device driver? > > I'm writing a driver for a OCP TimeCard. The card has several different > functions, each "tied" to a specific msi interrupt. So it would be useful > to use multiple msi interrupts. The PCIe functionality is a Xilinx AXI PCIe > blob, with 32 MSI interrupts. It does not have MSI-X capability. > > > # pciconf -lbc none1@pci0:1:0:0: > none0@pci0:1:0:0: class=0x058000 rev=0x00 hdr=0x00 vendor=0x1d9b > device=0x0400 subvendor=0x10ee subdevice=0x0007 > bar [10] = type Memory, range 32, base 0xf4000000, size 33554432, > enabled > cap 01[40] = powerspec 3 supports D0 D3 current D0 > cap 05[48] = MSI supports 32 messages, 64 bit > cap 10[60] = PCI-Express 2 endpoint max data 256(256) NS > max read 512 > link x1(x1) speed 2.5(2.5) ASPM disabled(L0s) > ecap 0003[100] = Serial 1 0000000000000000 > > > Currently in attach, I'm doing the following (error checking removed): > > > pci_enable_busmaster(dev); /* msi irq needs it enabled, at least for the > AXI core */ > sc->sc_msi = pci_msi_count(dev); > pci_alloc_msi(dev, &sc->sc_msi) > loop for each function /* currently just a single iteration to get one > function working */ > port->pp_irid = port->intr_num + 1; /* msi irq no starts at one */ > port->pp_ires = bus_alloc_resource_any(dev, SYS_RES_IRQ, > &port->pp_irid, RF_ACTIVE | RF_SHAREABLE); > bus_setup_intr(dev, port->pp_ires, INTR_TYPE_TTY | INTR_MPSAFE, > timecard_intr, NULL, port, &port->p_ihandle) > > > I did define a variable timecard_intr_count that timecard_intr() should > increment, but it does not change, so timecard_intr() probably does not get > called. > > Here is the console output of the panic and a show apic and show lapic. > The driver is not compiled in, but loaded later manually. > > > pci0: driver added > found-> vendor=0x8086, dev=0x1e3a, revid=0x04 > domain=0, bus=0, slot=22, func=0 > class=07-80-00, hdrtype=0x00, mfdev=1 > cmdreg=0x0006, statreg=0x0010, cachelnsz=0 (dwords) > lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) > intpin=a, irq=16 > powerspec 3 supports D0 D3 current D0 > MSI supports 1 message, 64 bit > pci0:0:22:0: reprobing on driver added > timecard0: TimeCard Probe > Vendor ID : 0x8086 > Device ID : 0x1e3a > pci1: driver added > found-> vendor=0x1d9b, dev=0x0400, revid=0x00 > domain=0, bus=1, slot=0, func=0 > class=05-80-00, hdrtype=0x00, mfdev=0 > cmdreg=0x0002, statreg=0x0010, cachelnsz=16 (dwords) > lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) > powerspec 3 supports D0 D3 current D0 > MSI supports 32 messages, 64 bit > pci0:1:0:0: reprobing on driver added > timecard0: TimeCard Probe > Vendor ID : 0x1d9b > Device ID : 0x400 > We've got the TimeCard, probe successful! > timecard0: TimeCard Probe > Vendor ID : 0x1d9b > Device ID : 0x400 > We've got the TimeCard, probe successful! > timecard0: mem 0xf4000000-0xf5ffffff at device 0.0 on pci1 > TimeCard Attach for : deviceID : 0x4001d9b > Address of timecard_intr_count 0xffffffff8314e400 > timecard0: attempting to allocate 32 MSI vectors (32 supported) > msi: routing MSI IRQ 38 to local APIC 4 vector 80 > msi: routing MSI IRQ 39 to local APIC 4 vector 81 > msi: routing MSI IRQ 40 to local APIC 4 vector 82 > msi: routing MSI IRQ 41 to local APIC 4 vector 83 > msi: routing MSI IRQ 42 to local APIC 4 vector 84 > msi: routing MSI IRQ 43 to local APIC 4 vector 85 > msi: routing MSI IRQ 44 to local APIC 4 vector 86 > msi: routing MSI IRQ 45 to local APIC 4 vector 87 > msi: routing MSI IRQ 46 to local APIC 4 vector 88 > msi: routing MSI IRQ 47 to local APIC 4 vector 89 > msi: routing MSI IRQ 48 to local APIC 4 vector 90 > msi: routing MSI IRQ 49 to local APIC 4 vector 91 > msi: routing MSI IRQ 50 to local APIC 4 vector 92 > msi: routing MSI IRQ 51 to local APIC 4 vector 93 > msi: routing MSI IRQ 52 to local APIC 4 vector 94 > msi: routing MSI IRQ 53 to local APIC 4 vector 95 > msi: routing MSI IRQ 54 to local APIC 4 vector 96 > msi: routing MSI IRQ 55 to local APIC 4 vector 97 > msi: routing MSI IRQ 56 to local APIC 4 vector 98 > msi: routing MSI IRQ 57 to local APIC 4 vector 99 > msi: routing MSI IRQ 58 to local APIC 4 vector 100 > msi: routing MSI IRQ 59 to local APIC 4 vector 101 > msi: routing MSI IRQ 60 to local APIC 4 vector 102 > msi: routing MSI IRQ 61 to local APIC 4 vector 103 > msi: routing MSI IRQ 62 to local APIC 4 vector 104 > msi: routing MSI IRQ 63 to local APIC 4 vector 105 > msi: routing MSI IRQ 64 to local APIC 4 vector 106 > msi: routing MSI IRQ 65 to local APIC 4 vector 107 > msi: routing MSI IRQ 66 to local APIC 4 vector 108 > msi: routing MSI IRQ 67 to local APIC 4 vector 109 > msi: routing MSI IRQ 68 to local APIC 4 vector 110 > msi: routing MSI IRQ 69 to local APIC 4 vector 111 > timecard0: using IRQs 38-69 for MSI > TimeCard msi 32 > rman iomem start f4000000, end f5ffffff, size 2000000 > timecard_corelist_read did not find list, using fb list 1 > nports 1 > Start with uart 0 0 > irq 41, irid 4 > > > Fatal trap 30: reserved (unknown) fault while in kernel mode > cpuid = 2; apic id = 04 > port irq rid 4 > instruction pointer = 0x20:0xffffffff804dda2d > stack pointer = 0x28:0xfffffe001b1d8de0 > TimeCard device loaded. > pci2: driver added > pci3: driver added > pci4: driver added > frame pointer = 0x28:0xfffffe001b1d8e10 > code segment = base 0x0, limit 0xfffff, type 0x1b > pci5: driver added > = DPL 0, pres 1, long 1, def32 0, gran 1 > processor eflags = interrupt enabled, IOPL = 0 > current process = 11 (idle: cpu2) > trap number = 30 > panic: reserved (unknown) fault > cpuid = 2 > time = 1695375919 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame > 0xfffffe001b1d8c00 > vpanic() at vpanic+0x151/frame 0xfffffe001b1d8c50 > panic() at panic+0x43/frame 0xfffffe001b1d8cb0 > trap_fatal() at trap_fatal+0x387/frame 0xfffffe001b1d8d10 > calltrap() at calltrap+0x8/frame 0xfffffe001b1d8d10 > --- trap 0x1e, rip = 0xffffffff804dda2d, rsp = 0xfffffe001b1d8de0, rbp = > 0xfffffe001b1d8e10 --- > acpi_cpu_idle() at acpi_cpu_idle+0x28d/frame 0xfffffe001b1d8e10 > cpu_idle_acpi() at cpu_idle_acpi+0x4d/frame 0xfffffe001b1d8e30 > cpu_idle() at cpu_idle+0xac/frame 0xfffffe001b1d8e50 > sched_idletd() at sched_idletd+0x4b1/frame 0xfffffe001b1d8ef0 > fork_exit() at fork_exit+0x80/frame 0xfffffe001b1d8f30 > fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe001b1d8f30 > --- trap 0xe0c2545f, rip = 0x8f4a0c76246ffed9, rsp = 0x670c1cf091ea5e5b, > rbp = 0x57639a151e2b2985 --- > KDB: enter: panic > [ thread pid 11 tid 100005 ] > Stopped at kdb_enter+0x37: movq $0,0x129840e(%rip) > db> x/wx timecard_intr_count > timecard_intr_count: 0 > db> show apic > Interrupts bound to lapic 0 > vec 0x30 -> IRQ 9 > vec 0x31 -> IRQ 28 > vec 0x32 -> IRQ 31 > vec 0x33 -> IRQ 24 > vec 0x34 -> IRQ 29 > vec 0x35 -> IRQ 30 > vec 0x36 -> IRQ 8 > vec 0x37 -> IRQ 16 > vec 0x38 -> IRQ 36 > vec 0x39 -> IRQ 1 > vec 0xef -> lapic timer > Interrupts bound to lapic 2 > vec 0x30 -> IRQ 25 > vec 0x31 -> IRQ 33 > vec 0x32 -> IRQ 23 > vec 0x33 -> IRQ 18 > vec 0xef -> lapic timer > Interrupts bound to lapic 4 > vec 0x30 -> IRQ 26 > vec 0x31 -> IRQ 0 > vec 0x32 -> IRQ 34 > vec 0x33 -> IRQ 37 > vec 0x50 -> IRQ 38 > vec 0x51 -> IRQ 39 > vec 0x52 -> IRQ 40 > vec 0x53 -> IRQ 41 > vec 0x54 -> IRQ 42 > vec 0x55 -> IRQ 43 > vec 0x56 -> IRQ 44 > vec 0x57 -> IRQ 45 > vec 0x58 -> IRQ 46 > vec 0x59 -> IRQ 47 > vec 0x5a -> IRQ 48 > vec 0x5b -> IRQ 49 > vec 0x5c -> IRQ 50 > vec 0x5d -> IRQ 51 > vec 0x5e -> IRQ 52 > vec 0x5f -> IRQ 53 > vec 0x60 -> IRQ 54 > vec 0x61 -> IRQ 55 > vec 0x62 -> IRQ 56 > vec 0x63 -> IRQ 57 > vec 0x64 -> IRQ 58 > vec 0x65 -> IRQ 59 > vec 0x66 -> IRQ 60 > vec 0x67 -> IRQ 61 > vec 0x68 -> IRQ 62 > vec 0x69 -> IRQ 63 > vec 0x6a -> IRQ 64 > vec 0x6b -> IRQ 65 > vec 0x6c -> IRQ 66 > vec 0x6d -> IRQ 67 > vec 0x6e -> IRQ 68 > vec 0x6f -> IRQ 69 > vec 0xef -> lapic timer > Interrupts bound to lapic 6 > vec 0x30 -> IRQ 27 > vec 0x31 -> IRQ 32 > vec 0x32 -> IRQ 35 > vec 0x33 -> IRQ 4 > vec 0xef -> lapic timer > db> show lapic > lapic ID = 4 > version = 1.5 > max LVT = 6 > SVR = ff (enabled) > TPR = 00 > In-service Interrupts: > isr2: 43 > TMR Interrupts: > IRR Interrupts: > irr1: 32 33 > irr2: 43 > irr7: ef > db> > > > Regards > > John > > --00000000000045eb7206062ac5dc Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Hi,

I found the cause of the= panics and thought I should give feedback here.

M= SI interrupt vectors have to be aligned to the size of the allocation, whic= h have to be in powers of 2 up to a maximum of 32 vectors.

native_apic_alloc_vectors(), which is used by pci_alloc_msi(), does not= properly align the vectors that it allocates. It does an aligned check, bu= t then after that adds APIC_IO_INTS, which is 48, and so the alignment is l= ost. So allocating smaller numbers of vectors would work because 48 is a mu= ltiple of 16.

If you allocate 32 MSI interrupts, the= pcie card just ignores the bottom 5 bits of the vector that was written to= its MSI_DATA register, so in my case where native_apic_alloc_vectors() all= ocated a base vector of 0x50, the card ignores bit 4 and generates interrup= t vectors from 0x40 to 0x5f.

I have opened a bug r= eport about it:

Regards

John


On Fri, 22 Sept 2023 at 13:00, John Hay <john@sanren.ac.za> wrote:
Hi,

How do one debug msi interrupts on FreeBSD when writing a = device driver?

I'm writing a driver for a OCP = TimeCard. The card has several different functions, each "tied" t= o a specific msi interrupt. So it would be useful to use multiple msi inter= rupts. The PCIe functionality is a Xilinx AXI PCIe blob, with 32 MSI interr= upts. It does not have MSI-X capability.

<s= nip>
# pciconf -lbc none1@pci0:1:0:0:
none0@pci0:1:0:0:= class=3D0x058000 rev=3D0x00 hdr=3D0x00 vendor=3D0x1d9b device=3D0x0400 sub= vendor=3D0x10ee subdevice=3D0x0007
=C2=A0 =C2=A0 bar =C2=A0 [10] =3D typ= e Memory, range 32, base 0xf4000000, size 33554432, enabled
=C2=A0 =C2= =A0 cap 01[40] =3D powerspec 3 =C2=A0supports D0 D3 =C2=A0current D0
=C2= =A0 =C2=A0 cap 05[48] =3D MSI supports 32 messages, 64 bit
=C2=A0 =C2= =A0 cap 10[60] =3D PCI-Express 2 endpoint max data 256(256) NS
=C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0max read 512
=C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0link x1(x1) spee= d 2.5(2.5) ASPM disabled(L0s)
=C2=A0 =C2=A0 ecap 0003[100] =3D Serial 1 = 0000000000000000
</snip>

C= urrently in attach, I'm doing the following (error checking removed):

<snip>
pci_enable_busmaster(dev= ); /* msi irq needs it enabled, at least for the AXI core */
= sc->sc_msi =3D pci_msi_count(dev);
pci_alloc_msi(dev, &sc-= >sc_msi)
loop for each function /* currently just a single ite= ration to get one function working */
=C2=A0=C2=A0 port->p= p_irid =3D port->intr_num + 1; /* msi irq no starts at one */
<= div>=C2=A0=C2=A0 port->pp_ires =3D bus_alloc_resource_any(dev, SYS_RES_I= RQ, &port->pp_irid, RF_ACTIVE | RF_SHAREABLE);
=C2=A0=C2= =A0 bus_setup_intr(dev, port->pp_ires, INTR_TYPE_TTY | INTR_MPSAFE, time= card_intr, NULL, port, &port->p_ihandle)
</snip>

I did define a variable timecard_intr_count that time= card_intr() should increment, but it does not change, so timecard_intr() pr= obably does not get called.

Here is the console ou= tput of the panic and a show apic and show lapic. The driver is not compile= d in, but loaded later manually.

<snip>
pci0: driver added
found-> vendor=3D0x8086, dev=3D0x1e3a, revid= =3D0x04
=C2=A0 =C2=A0 =C2=A0 =C2=A0 domain=3D0, bus=3D0, slot=3D22, func= =3D0
=C2=A0 =C2=A0 =C2=A0 =C2=A0 class=3D07-80-00, hdrtype=3D0x00, mfdev= =3D1
=C2=A0 =C2=A0 =C2=A0 =C2=A0 cmdreg=3D0x0006, statreg=3D0x0010, cach= elnsz=3D0 (dwords)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 lattimer=3D0x00 (0 ns), m= ingnt=3D0x00 (0 ns), maxlat=3D0x00 (0 ns)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 in= tpin=3Da, irq=3D16
=C2=A0 =C2=A0 =C2=A0 =C2=A0 powerspec 3 =C2=A0support= s D0 D3 =C2=A0current D0
=C2=A0 =C2=A0 =C2=A0 =C2=A0 MSI supports 1 mess= age, 64 bit
pci0:0:22:0: reprobing on driver added
timecard0: TimeCar= d Probe
Vendor ID : 0x8086
Device ID : 0x1e3a
pci1: driver addedfound-> vendor=3D0x1d9b, dev=3D0x0400, revid=3D0x00
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 domain=3D0, bus=3D1, slot=3D0, func=3D0
=C2=A0 =C2=A0 =C2= =A0 =C2=A0 class=3D05-80-00, hdrtype=3D0x00, mfdev=3D0
=C2=A0 =C2=A0 =C2= =A0 =C2=A0 cmdreg=3D0x0002, statreg=3D0x0010, cachelnsz=3D16 (dwords)
= =C2=A0 =C2=A0 =C2=A0 =C2=A0 lattimer=3D0x00 (0 ns), mingnt=3D0x00 (0 ns), m= axlat=3D0x00 (0 ns)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 powerspec 3 =C2=A0suppor= ts D0 D3 =C2=A0current D0
=C2=A0 =C2=A0 =C2=A0 =C2=A0 MSI supports 32 me= ssages, 64 bit
pci0:1:0:0: reprobing on driver added
timecard0: TimeC= ard Probe
Vendor ID : 0x1d9b
Device ID : 0x400
We've got the T= imeCard, probe successful!
timecard0: TimeCard Probe
Vendor ID : 0x1d= 9b
Device ID : 0x400
We've got the TimeCard, probe successful!timecard0: <TimeCard> mem 0xf4000000-0xf5ffffff at device 0.0 on pci= 1
TimeCard Attach for : deviceID : 0x4001d9b
Address of timecard_intr= _count 0xffffffff8314e400
timecard0: attempting to allocate 32 MSI vecto= rs (32 supported)
msi: routing MSI IRQ 38 to local APIC 4 vector 80
m= si: routing MSI IRQ 39 to local APIC 4 vector 81
msi: routing MSI IRQ 40= to local APIC 4 vector 82
msi: routing MSI IRQ 41 to local APIC 4 vecto= r 83
msi: routing MSI IRQ 42 to local APIC 4 vector 84
msi: routing M= SI IRQ 43 to local APIC 4 vector 85
msi: routing MSI IRQ 44 to local API= C 4 vector 86
msi: routing MSI IRQ 45 to local APIC 4 vector 87
msi: = routing MSI IRQ 46 to local APIC 4 vector 88
msi: routing MSI IRQ 47 to = local APIC 4 vector 89
msi: routing MSI IRQ 48 to local APIC 4 vector 90=
msi: routing MSI IRQ 49 to local APIC 4 vector 91
msi: routing MSI I= RQ 50 to local APIC 4 vector 92
msi: routing MSI IRQ 51 to local APIC 4 = vector 93
msi: routing MSI IRQ 52 to local APIC 4 vector 94
msi: rout= ing MSI IRQ 53 to local APIC 4 vector 95
msi: routing MSI IRQ 54 to loca= l APIC 4 vector 96
msi: routing MSI IRQ 55 to local APIC 4 vector 97
= msi: routing MSI IRQ 56 to local APIC 4 vector 98
msi: routing MSI IRQ 5= 7 to local APIC 4 vector 99
msi: routing MSI IRQ 58 to local APIC 4 vect= or 100
msi: routing MSI IRQ 59 to local APIC 4 vector 101
msi: routin= g MSI IRQ 60 to local APIC 4 vector 102
msi: routing MSI IRQ 61 to local= APIC 4 vector 103
msi: routing MSI IRQ 62 to local APIC 4 vector 104msi: routing MSI IRQ 63 to local APIC 4 vector 105
msi: routing MSI IRQ= 64 to local APIC 4 vector 106
msi: routing MSI IRQ 65 to local APIC 4 v= ector 107
msi: routing MSI IRQ 66 to local APIC 4 vector 108
msi: rou= ting MSI IRQ 67 to local APIC 4 vector 109
msi: routing MSI IRQ 68 to lo= cal APIC 4 vector 110
msi: routing MSI IRQ 69 to local APIC 4 vector 111=
timecard0: using IRQs 38-69 for MSI
TimeCard msi 32
rman iomem st= art f4000000, end f5ffffff, size 2000000
timecard_corelist_read did not = find list, using fb list 1
nports 1
Start with uart 0 0
irq 41, ir= id 4


Fatal trap 30: reserved (unknown) fault while in kernel mod= e
cpuid =3D 2; apic id =3D 04
port irq rid 4
instruction pointer = =C2=A0 =C2=A0 =3D 0x20:0xffffffff804dda2d
stack pointer =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =3D 0x28:0xfffffe001b1d8de0
TimeCard device loaded.=
pci2: driver added
pci3: driver added
pci4: driver added
frame= pointer =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =3D 0x28:0xfffffe001b1d8e10
= code segment =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0=3D base 0x0, limit 0= xfffff, type 0x1b
pci5: driver added
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =3D DPL 0, pres 1, lon= g 1, def32 0, gran 1
processor eflags =C2=A0 =C2=A0 =C2=A0 =C2=A0=3D int= errupt enabled, IOPL =3D 0
current process =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =3D 11 (idle: cpu2)
trap number =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =3D 30
panic: reserved (unknown) fault
cpuid =3D 2
time =3D 16= 95375919
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_se= lf_wrapper+0x2b/frame 0xfffffe001b1d8c00
vpanic() at vpanic+0x151/frame = 0xfffffe001b1d8c50
panic() at panic+0x43/frame 0xfffffe001b1d8cb0
tra= p_fatal() at trap_fatal+0x387/frame 0xfffffe001b1d8d10
calltrap() at cal= ltrap+0x8/frame 0xfffffe001b1d8d10
--- trap 0x1e, rip =3D 0xffffffff804d= da2d, rsp =3D 0xfffffe001b1d8de0, rbp =3D 0xfffffe001b1d8e10 ---
acpi_cp= u_idle() at acpi_cpu_idle+0x28d/frame 0xfffffe001b1d8e10
cpu_idle_acpi()= at cpu_idle_acpi+0x4d/frame 0xfffffe001b1d8e30
cpu_idle() at cpu_idle+0= xac/frame 0xfffffe001b1d8e50
sched_idletd() at sched_idletd+0x4b1/frame = 0xfffffe001b1d8ef0
fork_exit() at fork_exit+0x80/frame 0xfffffe001b1d8f3= 0
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe001b1d8f30
-= -- trap 0xe0c2545f, rip =3D 0x8f4a0c76246ffed9, rsp =3D 0x670c1cf091ea5e5b,= rbp =3D 0x57639a151e2b2985 ---
KDB: enter: panic
[ thread pid 11 tid= 100005 ]
Stopped at =C2=A0 =C2=A0 =C2=A0kdb_enter+0x37: movq =C2=A0 =C2= =A0$0,0x129840e(%rip)
db> x/wx timecard_intr_count
timecard_intr_c= ount: =C2=A0 =C2=A00
db> show apic
Interrupts bound to lapic 0
= vec 0x30 -> IRQ 9
vec 0x31 -> IRQ 28
vec 0x32 -> IRQ 31
v= ec 0x33 -> IRQ 24
vec 0x34 -> IRQ 29
vec 0x35 -> IRQ 30
v= ec 0x36 -> IRQ 8
vec 0x37 -> IRQ 16
vec 0x38 -> IRQ 36
ve= c 0x39 -> IRQ 1
vec 0xef -> lapic timer
Interrupts bound to lap= ic 2
vec 0x30 -> IRQ 25
vec 0x31 -> IRQ 33
vec 0x32 -> IR= Q 23
vec 0x33 -> IRQ 18
vec 0xef -> lapic timer
Interrupts b= ound to lapic 4
vec 0x30 -> IRQ 26
vec 0x31 -> IRQ 0
vec 0x3= 2 -> IRQ 34
vec 0x33 -> IRQ 37
vec 0x50 -> IRQ 38
vec 0x5= 1 -> IRQ 39
vec 0x52 -> IRQ 40
vec 0x53 -> IRQ 41
vec 0x5= 4 -> IRQ 42
vec 0x55 -> IRQ 43
vec 0x56 -> IRQ 44
vec 0x5= 7 -> IRQ 45
vec 0x58 -> IRQ 46
vec 0x59 -> IRQ 47
vec 0x5= a -> IRQ 48
vec 0x5b -> IRQ 49
vec 0x5c -> IRQ 50
vec 0x5= d -> IRQ 51
vec 0x5e -> IRQ 52
vec 0x5f -> IRQ 53
vec 0x6= 0 -> IRQ 54
vec 0x61 -> IRQ 55
vec 0x62 -> IRQ 56
vec 0x6= 3 -> IRQ 57
vec 0x64 -> IRQ 58
vec 0x65 -> IRQ 59
vec 0x6= 6 -> IRQ 60
vec 0x67 -> IRQ 61
vec 0x68 -> IRQ 62
vec 0x6= 9 -> IRQ 63
vec 0x6a -> IRQ 64
vec 0x6b -> IRQ 65
vec 0x6= c -> IRQ 66
vec 0x6d -> IRQ 67
vec 0x6e -> IRQ 68
vec 0x6= f -> IRQ 69
vec 0xef -> lapic timer
Interrupts bound to lapic 6=
vec 0x30 -> IRQ 27
vec 0x31 -> IRQ 32
vec 0x32 -> IRQ 35=
vec 0x33 -> IRQ 4
vec 0xef -> lapic timer
db> show lapic=
lapic ID =3D 4
version =C2=A0=3D 1.5
max LVT =C2=A0=3D 6
SVR = =C2=A0 =C2=A0 =C2=A0=3D ff (enabled)
TPR =C2=A0 =C2=A0 =C2=A0=3D 00
I= n-service Interrupts:
isr2: 43
TMR Interrupts:
IRR Interrupts:
= irr1: 32 33
irr2: 43
irr7: ef
db>
</snip><= /div>

Regards

John
--00000000000045eb7206062ac5dc--