12.3: kernel crash when stopping disks

From: Peter <pmc_at_citylink.dinoex.sub.org>
Date: Sun, 05 Dec 2021 02:27:41 UTC
Hija,

  that one doesn' seem to like me. 

Dec  5 01:08:14 <local0.info> edge gstopd[8837]: da0:    0@Sun Dec  5 01:08:14 2021 
Dec  5 01:08:25 <local0.info> edge gstopd[64139]: Error received from stop unit command
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: Recovery Initiated - Card was not paused
Dec  5 01:08:25 <kern.crit> edge kernel: >>>>>>>>>>>>>>>>>> Dump Card State Begins <<<<<<<<<<<<<<<<<
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: Dumping Card State at program address 0x7e Mode 0x22
Dec  5 01:08:25 <kern.crit> edge kernel: INTSTAT[0x0] SELOID[0x0] SELID[0x20] HS_MAILBOX[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: INTCTL[0xc0] SEQINTSTAT[0x10] SAVED_MODE[0x11] DFFSTAT[0x33] 
Dec  5 01:08:25 <kern.crit> edge kernel: SCSISIGI[0x0] SCSIPHASE[0x0] SCSIBUS[0x0] LASTPHASE[0x1] 
Dec  5 01:08:25 <kern.crit> edge kernel: SCSISEQ0[0x0] SCSISEQ1[0x12] SEQCTL0[0x0] SEQINTCTL[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: SEQ_FLAGS[0xc0] SEQ_FLAGS2[0x0] QFREEZE_COUNT[0x1b] 
Dec  5 01:08:25 <kern.crit> edge kernel: KERNEL_QFREEZE_COUNT[0x1b] MK_MESSAGE_SCB[0xff00] 
Dec  5 01:08:25 <kern.crit> edge kernel: MK_MESSAGE_SCSIID[0xff] SSTAT0[0x0] SSTAT1[0x8] SSTAT2[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: SSTAT3[0x0] PERRDIAG[0x0] SIMODE1[0xa4] LQISTAT0[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: LQISTAT1[0x0] LQISTAT2[0x0] LQOSTAT0[0x0] LQOSTAT1[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: LQOSTAT2[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: 
Dec  5 01:08:25 <kern.crit> edge kernel: SCB Count = 512 CMDS_PENDING = 3 LASTSCB 0xf3 CURRSCB 0xf7 NEXTSCB 0xff00
Dec  5 01:08:25 <kern.crit> edge kernel: qinstart = 17017 qinfifonext = 17017
Dec  5 01:08:25 <kern.crit> edge kernel: QINFIFO:
Dec  5 01:08:25 <kern.crit> edge kernel: WAITING_TID_QUEUES:
Dec  5 01:08:25 <kern.crit> edge kernel: Pending list:
Dec  5 01:08:25 <kern.crit> edge kernel: 247 FIFO_USE[0x0] SCB_CONTROL[0x64] SCB_SCSIID[0x7] 
Dec  5 01:08:25 <kern.crit> edge kernel: 499 FIFO_USE[0x0] SCB_CONTROL[0x64] SCB_SCSIID[0x7] 
Dec  5 01:08:25 <kern.crit> edge kernel: 252 FIFO_USE[0x0] SCB_CONTROL[0x66] SCB_SCSIID[0x7] 
Dec  5 01:08:25 <kern.crit> edge kernel: Total 3
Dec  5 01:08:25 <kern.crit> edge kernel: Kernel Free SCB lists: 
Dec  5 01:08:25 <kern.crit> edge kernel:   COLIDX[0]: 243 503 508 
Dec  5 01:08:25 <kern.crit> edge kernel:   Any Device: 254 510 506 250 242 498 500 244 507 251 245 501 248 249 504 505 253 502 246 509 497 241 239 495 240 496 255 511 494 493 492 491 490 489 488 487 486 485 484 483 482 481 480 479 478 477 476 475 474 473 472 471 470 469 468 467 466 465 464 463 462 461 460 459 458 457 456 455 454 453 452 451 450 449 448 447 446 445 444 443 442 441 440 439 438 437 436 435 434 433 432 431 430 429 428 427 426 425 424 423 422 421 420 419 418 417 416 415 414 413 412 411 410 409 408 407 406 405 404 403 402 401 400 399 398 397 396 395 394 393 392 391 390 389 388 387 386 385 384 383 382 381 380 379 378 377 376 375 374 373 372 371 370 369 368 367 366 365 364 363 362 361 360 359 358 357 356 355 354 353 352 351 350 349 348 347 346 345 344 343 342 341 340 339 338 337 336 335 334 333 332 331 330 329 328 327 326 325 324 323 322 321 320 319 318 317 316 315 314 313 312 311 310 309 308 307 306 305 304 303 302 301 300 299 298 297 296 295 294 293 292 291 290 289 288 287 286 285 284 283 282 281 280 279 278 277 276 275 274 273 272 271 270 269 268 267 266 265 264 263 262 261 260 259 258 257 256 238 237 236 235 234 233 232 231 230 229 228 227 226 225 224 223 222 221 220 219 218 217 216 215 214 213 212 211 210 209 208 207 206 205 204 203 202 201 200 199 198 197 196 195 194 193 192 191 190 189 188 187 186 185 184 183 182 181 180 179 178 177 176 175 174 173 172 171 170 169 168 167 166 165 164 163 162 161 160 159 158 157 156 155 154 153 152 151 150 149 148 147 146 145 144 143 142 141 140 139 138 137 136 135 134 133 132 131 130 129 128 127 126 125 124 123 122 121 120 119 118 117 116 115 114 113 112 111 110 109 108 107 106 105 104 103 102 101 100 99 98 97 96 95 94 93 92 91 90 89 88 87 86 85 84 83 82 81 80 79 78 77 76 75 74 73 72 71 70 69 68 67 66 65 64 63 62 61 60 59 58 57 56 55 54 53 52 51 50 49 48 47 46 45 44 43 42 41 40 39 38 37 36 35 34 33 32 31 30 29 28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 0 
Dec  5 01:08:25 <kern.crit> edge kernel: Sequencer Complete DMA-inprog list: 
Dec  5 01:08:25 <kern.crit> edge kernel: Sequencer Complete list: 
Dec  5 01:08:25 <kern.crit> edge kernel: Sequencer DMA-Up and Complete list: 
Dec  5 01:08:25 <kern.crit> edge kernel: Sequencer On QFreeze and Complete list: 
Dec  5 01:08:25 <kern.crit> edge kernel: 
Dec  5 01:08:25 <kern.crit> edge syslogd: last message repeated 1 times
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: FIFO0 Free, LONGJMP == 0x826c, SCB 0x1fc
Dec  5 01:08:25 <kern.crit> edge kernel: SEQIMODE[0x3f] SEQINTSRC[0x0] DFCNTRL[0x0] DFSTATUS[0x89] 
Dec  5 01:08:25 <kern.crit> edge kernel: SG_CACHE_SHADOW[0x2] SG_STATE[0x0] DFFSXFRCTL[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: SOFFCNT[0x0] MDFFSTAT[0x5] SHADDR = 0x00, SHCNT = 0x0 
Dec  5 01:08:25 <kern.crit> edge kernel: HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10] 
Dec  5 01:08:25 <kern.crit> edge kernel: 
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: FIFO1 Free, LONGJMP == 0x8254, SCB 0xf7
Dec  5 01:08:25 <kern.crit> edge kernel: SEQIMODE[0x3f] SEQINTSRC[0x0] DFCNTRL[0x4] DFSTATUS[0x89] 
Dec  5 01:08:25 <kern.crit> edge kernel: SG_CACHE_SHADOW[0x2] SG_STATE[0x0] DFFSXFRCTL[0x0] 
Dec  5 01:08:25 <kern.crit> edge kernel: SOFFCNT[0x0] MDFFSTAT[0x5] SHADDR = 0x00, SHCNT = 0x0 
Dec  5 01:08:25 <kern.crit> edge kernel: HADDR = 0x00, HCNT = 0x0 CCSGCTL[0x10] 
Dec  5 01:08:25 <kern.crit> edge kernel: LQIN: 0x8 0x0 0x1 0xfc 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: LQISTATE = 0x0, LQOSTATE = 0x0, OPTIONMODE = 0x52
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: OS_SPACE_CNT = 0x20 MAXCMDCNT = 0x1
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: SAVED_SCSIID = 0x0 SAVED_LUN = 0x0
Dec  5 01:08:25 <kern.crit> edge kernel: SIMODE0[0xc] 
Dec  5 01:08:25 <kern.crit> edge kernel: CCSCBCTL[0x4] 
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: REG0 == 0xf7, SINDEX = 0x1e0, DINDEX = 0xe1
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: SCBPTR == 0xfff3, SCB_NEXT == 0xff00, SCB_NEXT2 == 0xff1e
Dec  5 01:08:25 <kern.crit> edge kernel: CDB 28 0 0 9a d1 0
Dec  5 01:08:25 <kern.crit> edge kernel: STACK: 0x20 0x0 0x0 0x0 0x0 0x0 0x0 0x0
Dec  5 01:08:25 <kern.crit> edge kernel: <<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>
Dec  5 01:08:25 <kern.crit> edge kernel: (pass0:ahd0:0:0:0): SCB 247 - timed out
Dec  5 01:08:25 <kern.crit> edge kernel: (pass0:ahd0:0:0:0): Queuing a BDR SCB
Dec  5 01:08:25 <kern.crit> edge kernel: (pass0:ahd0:0:0:0): Bus Device Reset Message Sent
Dec  5 01:08:25 <kern.crit> edge kernel: (pass0:ahd0:0:0:0): no longer in timeout, status = 24b
Dec  5 01:08:25 <kern.crit> edge kernel: ahd0: Bus Device Reset on A:0. 3 SCBs aborted
Dec  5 01:08:25 <local0.info> edge gstopd[8837]: da1:    0@Sun Dec  5 01:08:25 2021 
Dec  5 01:08:35 <local0.info> edge gstopd[64691]: Unit stopped successfully
Dec  5 01:08:35 <local0.info> edge gstopd[8837]: da2:    0@Sun Dec  5 01:08:35 2021 
Dec  5 01:08:37 <kern.crit> edge kernel: (da0:ahd0:0:0:0): READ(10). CDB: 28 00 00 9a d1 00 00 00 08 00 
Dec  5 01:08:37 <kern.crit> edge kernel: (da0:ahd0:0:0:0): CAM status: SCSI Status Error
Dec  5 01:08:37 <kern.crit> edge kernel: (da0:ahd0:0:0:0): SCSI status: Check Condition
Dec  5 01:08:37 <kern.crit> edge kernel: (da0:ahd0:0:0:0): SCSI sense: UNIT ATTENTION asc:29,3 (Bus device reset function occurred)
Dec  5 01:08:37 <kern.crit> edge kernel: (da0:ahd0:0:0:0): Retrying command (per sense data)

And then in the vmcore:

<<<<<<<<<<<<<<<<< Dump Card State Ends >>>>>>>>>>>>>>>>>>
(pass0:ahd0:0:0:0): SCB 247 - timed out
(pass0:ahd0:0:0:0): Queuing a BDR SCB
(pass0:ahd0:0:0:0): Bus Device Reset Message Sent
(pass0:ahd0:0:0:0): no longer in timeout, status = 24b
ahd0: Bus Device Reset on A:0. 3 SCBs aborted
(da0:ahd0:0:0:0): READ(10). CDB: 28 00 00 9a d1 00 00 00 08 00 
(da0:ahd0:0:0:0): CAM status: SCSI Status Error
(da0:ahd0:0:0:0): SCSI status: Check Condition
(da0:ahd0:0:0:0): SCSI sense: UNIT ATTENTION asc:29,3 (Bus device reset function occurred)
(da0:ahd0:0:0:0): Retrying command (per sense data)


Fatal trap 12: page fault while in kernel mode
cpuid = 1; apic id = 01
fault virtual address   = 0x0
fault code              = supervisor read data, page not present
instruction pointer     = 0x20:0xffffffff805cb396
stack pointer           = 0x28:0xfffffe009b2f9a90
frame pointer           = 0x28:0xfffffe009b2f9b10
code segment            = base 0x0, limit 0xfffff, type 0x1b
                        = DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags        = interrupt enabled, resume, IOPL = 0
current process         = 11 (irq26: ahd0)
trap number             = 12
panic: page fault
cpuid = 1
time = 1638662925
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe009b2f9750
vpanic() at vpanic+0x17b/frame 0xfffffe009b2f97a0
panic() at panic+0x43/frame 0xfffffe009b2f9800
trap_fatal() at trap_fatal+0x391/frame 0xfffffe009b2f9860
trap_pfault() at trap_pfault+0x4f/frame 0xfffffe009b2f98b0
trap() at trap+0x4cf/frame 0xfffffe009b2f99c0
calltrap() at calltrap+0x8/frame 0xfffffe009b2f99c0
--- trap 0xc, rip = 0xffffffff805cb396, rsp = 0xfffffe009b2f9a90, rbp = 0xfffffe009b2f9b10 ---
ahd_handle_seqint() at ahd_handle_seqint+0x706/frame 0xfffffe009b2f9b10
ahd_intr() at ahd_intr+0x154/frame 0xfffffe009b2f9b30
ahd_platform_intr() at ahd_platform_intr+0x39/frame 0xfffffe009b2f9b50
ithread_loop() at ithread_loop+0x241/frame 0xfffffe009b2f9bb0
fork_exit() at fork_exit+0x82/frame 0xfffffe009b2f9bf0
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe009b2f9bf0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Uptime: 1h57m36s
(da0:ahd0:0:0:0): SYNCHRONIZE CACHE(10). CDB: 35 00 00 00 00 00 00 00 00 00 
(da0:ahd0:0:0:0): CAM status: Command timeout
(da0:ahd0:0:0:0): Error 5, Retries exhausted
(da0:ahd0:0:0:0): Synchronize cache failed
(da1:ahd0:0:2:0): SYNCHRONIZE CACHE(10). CDB: 35 00 00 00 00 00 00 00 00 00 
(da1:ahd0:0:2:0): CAM status: Command timeout
(da1:ahd0:0:2:0): Error 5, Retries exhausted
(da1:ahd0:0:2:0): Synchronize cache failed
(da2:ahd0:0:4:0): SYNCHRONIZE CACHE(10). CDB: 35 00 00 00 00 00 00 00 00 00 
(da2:ahd0:0:4:0): CAM status: Command timeout
(da2:ahd0:0:4:0): Error 5, Retries exhausted
(da2:ahd0:0:4:0): Synchronize cache failed