the following diagnostic is repeated several dozen times: (probe0:vtscsi0:0:115:0): Probe completed (probe0:vtscsi0:0:115:0): Periph invalidated (probe0:vtscsi0:0:115:0): Periph destroyed (probe0:vtscsi0:0:116:0): Periph created (probe0:vtscsi0:0:116:0): Probe started (probe0:vtscsi0:0:116:0): Probe PROBE_INVALID to PROBE_INQUIRY (probe0:vtscsi0:0:116:0): INQUIRY. CDB: 12 00 00 00 24 00 (probe0:vtscsi0:0:116:0): CAM status: Selection Timeout (probe0:vtscsi0:0:116:0): Error 6, Unretryable error (probe0:vtscsi0:0:116:0): (noperiph:vtscsi0:0:116:ffffffff): Probe PROBE_INQUIRY to PROBE_INVALID xpt_async(AC_LOST_DEVICE) (probe0:vtscsi0:0:116:0): Probe completed (probe0:vtscsi0:0:116:0): Periph invalidated (probe0:vtscsi0:0:116:0): Periph destroyed (probe0:vtscsi0:0:117:0): Periph created (probe0:vtscsi0:0:117:0): Probe started (probe0:vtscsi0:0:117:0): Probe PROBE_INVALID to PROBE_INQUIRY (probe0:vtscsi0:0:117:0): INQUIRY. CDB: 12 00 00 00 24 00 (probe0:vtscsi0:0:117:0): CAM status: Selection Timeout (probe0:vtscsi0:0:117:0): Error 6, Unretryable error (probe0:vtscsi0:0:117:0): (noperiph:vtscsi0:0:117:ffffffff): Probe PROBE_INQUIRY to PROBE_INVALID xpt_async(AC_LOST_DEVICE) eventually, we get: cd0 at vtscsi0 bus 0 scbus0 target 0 lun 0 cd0: <QEMU QEMU CD-ROM 2.5+> Removable CD-ROM SPC-3 SCSI device cd0: 300.000MB/s transfers cd0: Command Queueing enabled cd0: Attempt to query device size failed: NOT READY, Medium not present but the above diagnostic still keeps being repeated, until it's first interleaved, then overtaken by a new kind: (cd0:vtscsi0:0:0:0): cdclose (noperiph:vtscsi0:0:0:1): (cd0:vtscsi0:0:0:0): xpt_async(AC_GETDEV_CHANGED) cdopen (cd0:vtscsi0:0:0:0): READ CAPACITY. CDB: 25 00 00 00 00 00 00 00 00 00 (cd0:vtscsi0:0:0:0): CAM status: SCSI Status Error (cd0:vtscsi0:0:0:0): SCSI status: Check Condition (cd0:vtscsi0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) (cd0:vtscsi0:0:0:0): Error 6, Unretryable error (cd0:vtscsi0:0:0:0): cdclose (cd0:vtscsi0:0:0:0): cdopen (cd0:vtscsi0:0:0:0): READ CAPACITY. CDB: 25 00 00 00 00 00 00 00 00 00 (cd0:vtscsi0:0:0:0): CAM status: SCSI Status Error (cd0:vtscsi0:0:0:0): SCSI status: Check Condition (cd0:vtscsi0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) (cd0:vtscsi0:0:0:0): Error 6, Unretryable error (cd0:vtscsi0:0:0:0): cdclose (cd0:vtscsi0:0:0:0): cdopen (cd0:vtscsi0:0:0:0): READ CAPACITY. CDB: 25 00 00 00 00 00 00 00 00 00 (cd0:vtscsi0:0:0:0): CAM status: SCSI Status Error (cd0:vtscsi0:0:0:0): SCSI status: Check Condition (cd0:vtscsi0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) (cd0:vtscsi0:0:0:0): Error 6, Unretryable error (cd0:vtscsi0:0:0:0): cdclose (da0:vtscsi0:0:0:1): daopen (da0:vtscsi0:0:0:1): daclose (da0:vtscsi0:0:0:1): daopen (da0:vtscsi0:0:0:1): daclose (da0:vtscsi0:0:0:1): daopen (da0:vtscsi0:0:0:1): daclose (da0:vtscsi0:0:0:1): daopen (da0:vtscsi0:0:0:1): daclose (da0:vtscsi0:0:0:1): daopen (da0:vtscsi0:0:0:1): daclose (da0:vtscsi0:0:0:1): daopen (da0:vtscsi0:0:0:1): daclose (da0:vtscsi0:0:0:1): daopen with that out of the way, we get to a new sequence: (cd0:vtscsi0:0:0:0): TEST UNIT READY. CDB: 00 00 00 00 00 00 (cd0:vtscsi0:0:0:0): CAM status: SCSI Status Error (cd0:vtscsi0:0:0:0): SCSI status: Check Condition (cd0:vtscsi0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) (cd0:vtscsi0:0:0:0): Error 6, Unretryable error (cd0:vtscsi0:0:0:0): TEST UNIT READY. CDB: 00 00 00 00 00 00 (cd0:vtscsi0:0:0:0): CAM status: SCSI Status Error (cd0:vtscsi0:0:0:0): SCSI status: Check Condition (cd0:vtscsi0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) (cd0:vtscsi0:0:0:0): Error 6, Unretryable error (cd0:vtscsi0:0:0:0): TEST UNIT READY. CDB: 00 00 00 00 00 00 (cd0:vtscsi0:0:0:0): CAM status: SCSI Status Error (cd0:vtscsi0:0:0:0): SCSI status: Check Condition (cd0:vtscsi0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) (cd0:vtscsi0:0:0:0): Error 6, Unretryable error etc…
so we get selection timeouts when we send the INQUIRY command. There's no device at those addresses. Why we do this for targets 1 through (or maybe 255), I know not. It's likely not relevant though. cdopen is called when we start to read from the CD device. We send a READ CAPACITY command to fine out how big the media is... only to be told there's no MEDIA... So maybe a config error on the other side of vtscsi?
just for completeness, the full dmesg: https://gist.github.com/7b4343df3c646d45f978b99e7cd7b19e (at least that part that wasn't overrun from the buffer already)
Can you up the msgbuf size to capture the start? But honestly, I'm not seeing any misbehavior so far.
(In reply to Warner Losh from comment #3) > Can you up the msgbuf size to capture the start? full dmesg: https://gist.github.com/c4772229c128d4c45ac18ac19a75475f > But honestly, I'm not seeing any misbehavior so far. I think the only real misbehaviour is: This trace on a RELEASE kernel. (and my misunderstanding of when to stop… like when something says that's an Error 6, Unretryable error)
Created attachment 246198 [details] Full dmesg attach https://gist.github.com/c4772229c128d4c45ac18ac19a75475f here, so we're not dependent on GitHub
note that setting kern.cam.dflags=1 (in loader.conf), which according to sys/cam/cam_debug.h is: CAM_DEBUG_INFO = 0x01, /* scsi commands, errors, data */ does not change anything about the output.
Hmmm.. OK. I see we have options CAMDEBUG and CAM_DEBUG_FLAGS in the MMCCAM kernel for reasons that I'm unsure of. But that explains the verbosity.
we might wanna reverse those in std.nodebug
(In reply to Warner Losh from comment #7) > we have options CAMDEBUG and CAM_DEBUG_FLAGS in the MMCCAM kernel I assume those were added as MMCCAM is experimental and debugging information is desired when something goes wrong. What we should do depends on how close we are to enabling `options MMCCAM` by default, I'd think.
(In reply to Ed Maste from comment #9) Yea... this bug is unrelated to mmc. We're ready for sure on arm64. Intel platforms have faster speeds / modes not yet implemented by cam mmc.