PowerMac G5 panic: "spin lock . . . held too long" with traceback and such [possibly iichb0 irq42 problem related]

Mark Millard marklmi at yahoo.com
Sun Apr 18 18:44:00 UTC 2021


Note: I am using a USB dongle for Ethernet, not built-in
Ethernet.

spin lock 0xc00000000169d808 (sleepq chain) held by 0xc00800000370c100 (tid 100034) too long
timeout stopping cpus
panic: spin lock held too long
cpuid = 0
time = 1618766961
KDB: stack backtrace:
0xc0080000c1ec8f70: at kdb_backtrace+0x60
0xc0080000c1ec9080: at vpanic+0x1e0
0xc0080000c1ec9130: at panic+0x40
0xc0080000c1ec9160: at _mtx_lock_indefinite_check+0xb4
0xc0080000c1ec91d0: at _mtx_lock_spin_cookie+0x10c
0xc0080000c1ec9250: at sleepq_lock+0xd8
0xc0080000c1ec9290: at _cv_wait+0x8c
0xc0080000c1ec9310: at usbd_do_request_flags+0x6f4
0xc0080000c1ec9440: at usbd_do_request_proc+0x98
0xc0080000c1ec94b0: at ure_miibus_readreg+0x18c
0xc0080000c1ec9530: at miibus_readreg+0x88
0xc0080000c1ec9570: at rgephy_linkup+0x13c
0xc0080000c1ec95b0: at rgephy_service+0x178
0xc0080000c1ec9640: at mii_tick+0x7c
0xc0080000c1ec9680: at ure_tick+0x314
0xc0080000c1ec9730: at ue_tick_task+0x40
0xc0080000c1ec9760: at usb_process+0x24c
0xc0080000c1ec9830: at fork_exit+0xd8
0xc0080000c1ec98c0: at fork_trampoline+0x18
0xc0080000c1ec98f0: at -0x4
KDB: enter: panic
[ thread pid 15 tid 100117 ]
Stopped at      kdb_enter+0x78: ori     r0, r0, 0x0

db> trace 100034
Tracing pid 12 tid 100034 td 0xc00800000370c100
saved LR(0xc00000000127c013) is invalid.

db> ps
. . .
   12     0     0     0  RL      (threaded)                  [intr]
. . .
100034                   Run     CPU 1                       [irq42: iichb0]
. . .
100117                   Run     CPU 0                       [ure0]
. . .

db> show allchains
. . .
chain 73:
 thread 100067 (pid 15, usbus4) is blocked on lock 0xc000000005df70e0 (sleep mutex) "USB device mutex"
 thread 100117 (pid 15, ure0) is running on CPU 0
chain . . .

(100034 did not show up.)

db> trace 100067
Tracing pid 15 tid 100067 td 0xc008000003a56b80
0xc008000078fc75d0: at mi_switch+0x144
0xc008000078fc7610: at turnstile_wait+0x414
0xc008000078fc7680: at __mtx_lock_sleep+0x188
0xc008000078fc7720: at usb_callback_proc+0x238
0xc008000078fc7760: at usb_process+0x24c
0xc008000078fc7830: at fork_exit+0xd8
0xc008000078fc78c0: at fork_trampoline+0x18
0xc008000078fc78f0: at -0x4

db> ps
. . .
   15     0     0     0  RL      (threaded)                  [usb]
. . .
100067                   L      *USB dev 0xc00000000541c240  [usbus4]
. . .
100117                   Run     CPU 0                       [ure0]
. . .
100034                   Run     CPU 1                       [irq42: iichb0]
. . .

db> show intrcnt
cpu0:decrementer        2695690
irq42: iichb0           5552572
irq33554488: htpic0     5552573
irq33554459: ohci0      18
irq33554460: ohci1      1
irq33554495: ohci2*     816155
irq33554471: ata0       75050
irq33554472:-wohci0     47
irq33554432:-tapci0     579751
irq33554492:-agpio0     1
irq33554458: iichb1     398
irq33554433: pcm0       1
irq33554552: IPI        5982757
cpu1:decrementer        2537712

(Is the 5552572+1=5552573 expected?)

db> show intr 
swi5: fast taskq (pid 12) {SOFT}
swi6: task queue (pid 12) {SOFT}
swi6: Giant taskq (pid 12) {SOFT}
swi3: vm (pid 12) {SOFT}
swi4: clock (0) (pid 12) {SOFT, NEED}
swi4: clock (1) (pid 12) {SOFT}
swi1: netisr 0 (pid 12) {SOFT}
irq33554488: htpic0 (no thread)
irq42: iichb0 (pid 12)
irq33554492:-agpio0 (pid 12)
irq33554493:-agpio1 (pid 12)
irq33554454: scc0 (no thread)
irq33554455: scc0 (no thread)
swi0: uart uart (pid 12) {SOFT}
irq33554458: iichb1 (pid 12)
irq33554433: pcm0 (pid 12)
irq33554459: ohci0 (pid 12)
irq33554460: ohci1 (pid 12)
irq33554495: ohci2* (pid 12)
irq33554471: ata0 (pid 12)
irq33554472:-wohci0 (pid 12)
irq33554473: gem0 (pid 12)
irq33554432:-tapci0 (pid 12)
irq33554552: IPI (no thread)


Note: I probably had minidump turned off.

Typing dump to the db> prompt got me a huge
number of "(CTRL-C to abort) ". CTRL-C did
abort the dump so I guess it was working. I
typed dump again. But that eventually failed
with:

  ... ok
  chunk 2: 1024MB (262144 pages)KDB: reentering
KDB: stack backtrace:
0xc00000000130f990: at kdb_backtrace+0x60
0xc00000000130faa0: at kdb_reenter+0x6c
0xc00000000130fb10: at trap+0x98
0xc00000000130fc70: at powerpc_interrupt+0x1b4
0xc00000000130fcc0: kernel DSI read trap @ 0x100000ff8 by memcpy+0xd0: srr1=0x9000000000001032
            r1=0xc00000000130ff70 cr=0x44882224 xer=0x20000000 ctr=0x200 r2=0xc00000000142c000 sr=0x40000000 frame=0xc00000000130fcf0
0xc00000000130ff70: at settime.laststep+0x34
0xc00000000130ffc0: at ata_dmaload+0x254
0xc000000001310050: at ata_begin_transaction+0x178
0xc0000000013100e0: at ataaction+0xa58
0xc000000001310180: at xpt_run_devq+0x500
0xc000000001310290: at xpt_action_default+0xa90
0xc000000001310350: at ata_action+0x174
0xc000000001310390: at xpt_action+0x40
0xc0000000013103c0: at cam_periph_runccb+0x158
0xc000000001310530: at adadump+0x1e4
0xc0000000013106f0: at dump_write+0x10c
0xc000000001310760: at _dump_append+0x184
0xc0000000013107f0: at dumpsys_cb_dumpdata+0x168
0xc0000000013108d0: at dumpsys_generic+0x548
0xc000000001310a50: at doadump+0xdc
0xc000000001310a90: at db_dump+0x60
0xc000000001310b00: at db_command+0x2f0
0xc000000001310c40: at db_command_loop+0x88
0xc000000001310cc0: at db_trap+0x178
0xc000000001310e20: at kdb_trap+0x25c
0xc000000001310f10: at db_trap_glue+0xb4
0xc000000001310f40: at dbtrap+0x144
0xc0080000c1ec9000: at kdb_enter+0x60
0xc0080000c1ec9080: at vpanic+0x224
0xc0080000c1ec9130: at panic+0x40
0xc0080000c1ec9160: at _mtx_lock_indefinite_check+0xb4
0xc0080000c1ec91d0: at _mtx_lock_spin_cookie+0x10c
0xc0080000c1ec9250: at sleepq_lock+0xd8
0xc0080000c1ec9290: at _cv_wait+0x8c
0xc0080000c1ec9310: at usbd_do_request_flags+0x6f4
0xc0080000c1ec9440: at usbd_do_request_proc+0x98
0xc0080000c1ec94b0: at ure_miibus_readreg+0x18c
0xc0080000c1ec9530: at miibus_readreg+0x88
0xc0080000c1ec9570: at rgephy_linkup+0x13c
0xc0080000c1ec95b0: at rgephy_service+0x178
0xc0080000c1ec9640: at mii_tick+0x7c
0xc0080000c1ec9680: at ure_tick+0x314
0xc0080000c1ec9730: at ue_tick_task+0x40
0xc0080000c1ec9760: at usb_process+0x24c
0xc0080000c1ec9830: at fork_exit+0xd8
0xc0080000c1ec98c0: at fork_trampoline+0x18
0xc0080000c1ec98f0: at -0x4
KDB: reentering
KDB: stack backtrace:
0xc008000004e5aaa0: at kdb_backtrace+0x60
0xc008000004e5abb0: at kdb_reenter+0x6c
0xc008000004e5ac20: at trap+0x98
0xc008000004e5ad80: at powerpc_interrupt+0x1b4
0xc008000004e5add0: kernel FPU trap by trapstk+0x18e0: srr1=0x9000000000001032
            r1=0xc008000004e5b080 cr=0x146c000 xer=0x78 ctr=0xc00000000024cf80 r2=0xc00000000127c01d frame=0xc008000004e5ae00
0xc008000004e5b080: at -0x4
0xc008000000025100: at -0x4
0xc008000000025dc0: at -0x4
KDB: reentering
KDB: stack backtrace:
. . .


===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)



More information about the freebsd-ppc mailing list