Date: Tue, 14 Nov 2000 10:39:43 -0500 (EST) From: Jeff Fellin <jkf@research.bell-labs.com> To: freebsd-scsi@FreeBSD.org Subject: SCSI target driver help Message-ID: <200011141539.KAA08238@aura.research.bell-labs.com>
next in thread | raw e-mail | index | archive | help
I am writing a SCSI target device driver to capture SCSI disk commands from a SCSI bus, and forward them to a user-level process for execution and tracing. I am using an Adaptec 2940 Ultra2 SCSI Adapter boards with external SCSI cables connecting the systems. My problem is the user-level process only works the first time it is started. However, when it is orderly terminated and restarted I receive a SCSI bus timeout on sending the first SCSI message response to an INQUIRY command. I have checked my code for static variables that may not have been cleared, turned on all cam debugging, enabled AHC_DEBUG, and added extra printf's in the aic7xxx driver to determine what information is different that could be causing the problem. My device driver processing of XPT_ACCEPT_TARGET_IO, XPT_CONT_TARGET_IO, and XPT_IMMED_NOTIFY. is very similar to the processing in cam/scsi/scsi_target.c. However, to my eyes the information SCB displayed in aic7xxx, appears identical with regards to the data control fields, but the second time it times out on transmission. I have compiled my kernel with INVARIANTS and INVARIANT_SUPPORT enabled. I'm including a copy of the /var/log/messages with diagnostic output. To determine what was happening, I had the two Adaptec boards connected in a back-to-back situation, so I could monitor the information sent to my driver with what it received. My driver prefix is targda. If anyone has ideas or suggestions on other areas to explore to determine why the problem occurs on the second execution of the user-level process, I would like to hear from you. Jeff Fellin fellin@lucent.com Here is the /var/log/messages output: Nov 13 14:04:02 nstg2 /kernel: (xpt0:xpt0:0:-1:-1): debugging flags now 8 STARTING USER-LEVEL PROCESS FIRST TIME Nov 13 14:04:02 nstg2 /kernel: (targda0:ahc2:0:0:0): Lun now enabled for target mode RESCAN AFTER START USER-LEVEL PROCESS FIRST TIME Nov 13 14:04:15 nstg2 /kernel: (probe0:ahc3:0:0:0): INQUIRY. CDB: 12 0 0 0 24 0 ## This is displayed in ahc_exec(). Nov 13 14:04:15 nstg2 /kernel: AHC softc(0xcf62b800) dev: cf618280 Nov 13 14:04:19 nstg2 /kernel: tag: 0 bsh: 2c00 dmatag: 0xcf62ab40 scb_data: 0xcf62b8fc Nov 13 14:04:19 nstg2 /kernel: pending ccbs: 0xcf7de800 num=1 Nov 13 14:04:23 nstg2 /kernel: sg_maps: 0xcf623700 num=1073741824 Nov 13 14:04:26 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:26 nstg2 /kernel: SCB 0xcf62d000 ccb 0xcf7de800 flags 4000 bus 7dfe0008 cnt 1 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f87000 control:0x40 tcl:0x0 cmdlen:6 cmdpointer:0x37020 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag 0 Nov 13 14:04:29 nstg2 /kernel: datlen:36 data:0x7dd17884 segs:0x1 segp:0x7dfe0008 Nov 13 14:04:29 nstg2 /kernel: sg_addr:7dd17884 sg_len:36 Nov 13 14:04:29 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:04:29 nstg2 /kernel: cdb:12 0 0 0 24 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:04:29 nstg2 /kernel: rtry: 4 func: 901 stat: 200 flags: 40 pid: 3 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 1, 0 Nov 13 14:04:29 nstg2 /kernel: XPT_ACCEPT ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db ## This indicates the user-level process has read the received ## INQUIRY command Nov 13 14:04:29 nstg2 /kernel: targdar putting atio(0xcf96b900) on xmit_ccb ## This indicates the user-level process is sending the response to ## the received INQUIRY command. The function flow is the same as ## in targwrite of cam/scsi/scsi_target.c in terms of calling ## targstrategy(), targrunqueue(), and targstart(). Nov 13 14:04:29 nstg2 /kernel: targdaw UIO cnt: 1 resid: 36 seg: 0 rw: 1 Nov 13 14:04:29 nstg2 /kernel: ATIO 0xcf96b900, bp 0xdbe16158 on work Nov 13 14:04:29 nstg2 /kernel: Bad ctio status 4a vs. 0 Nov 13 14:04:29 nstg2 /kernel: Sending CTIO CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 1 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 40 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:04:29 nstg2 /kernel: Thawing queue 40 ## This is in ahc_exec() Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf60d000) dev: cf618480 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2800 dmatag: 0xcf62af80 scb_data: 0xcf60d0fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7c2400 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf6237b0 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[0]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: lstate[0, 0xcf91fb40]: Nov 13 14:04:29 nstg2 /kernel: path(0xcf7b7f80): accept: cf96bb00, num=49 Nov 13 14:04:29 nstg2 /kernel: immed: cf96e600, num=50 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf6281c0 ccb 0xcf7c2400 flags 4000 bus 7dfdbe78 cnt 1 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f80380 control:0xc0 tcl:0x40 cmdlen:0 cmdpointer:0x400186 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag e Nov 13 14:04:29 nstg2 /kernel: datlen:36 data:0x1c82299c segs:0x1 segp:0x7dfdbe78 Nov 13 14:04:29 nstg2 /kernel: sg_addr:1c82299c sg_len:36 Nov 13 14:04:29 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:04:29 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 200 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: (probe0:ahc3:0:0:0): INQUIRY. CDB: 12 1 80 0 ff 0 Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf62b800) dev: cf618280 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2c00 dmatag: 0xcf62ab40 scb_data: 0xcf62b8fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7de800 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf623700 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf62d000 ccb 0xcf7de800 flags 4000 bus 7dfe0008 cnt 1 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f87000 control:0x40 tcl:0x0 cmdlen:6 cmdpointer:0x37020 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag 0 Nov 13 14:04:29 nstg2 /kernel: datlen:255 data:0x1a922400 segs:0x1 segp:0x7dfe0008 Nov 13 14:04:29 nstg2 /kernel: sg_addr:1a922400 sg_len:255 Nov 13 14:04:29 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:04:29 nstg2 /kernel: cdb:12 1 80 0 ff 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:04:29 nstg2 /kernel: rtry: 4 func: 901 stat: 200 flags: 40 pid: 3 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 1, 0 Nov 13 14:04:29 nstg2 /kernel: XPT_ACCEPT ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 800112 db6d00ff 6db6db6d db6db6db Nov 13 14:04:29 nstg2 /kernel: targdar putting atio(0xcf96b900) on xmit_ccb Nov 13 14:04:29 nstg2 /kernel: targdaw UIO cnt: 1 resid: 96 seg: 0 rw: 1 Nov 13 14:04:29 nstg2 /kernel: ATIO 0xcf96b900, bp 0xdbe16158 on work Nov 13 14:04:29 nstg2 /kernel: Sending CTIO CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 1 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0xebce399c dxfer_len: 96 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 40 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 800112 db6d00ff 6db6db6d db6db6db Nov 13 14:04:29 nstg2 /kernel: Thawing queue 40 Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf60d000) dev: cf618480 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2800 dmatag: 0xcf62af80 scb_data: 0xcf60d0fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7c2400 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf6237b0 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[0]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: lstate[0, 0xcf91fb40]: Nov 13 14:04:29 nstg2 /kernel: path(0xcf7b7f80): accept: cf96bb00, num=49 Nov 13 14:04:29 nstg2 /kernel: immed: cf96e600, num=50 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf6281c0 ccb 0xcf7c2400 flags 4000 bus 7dfdbe78 cnt 1 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f80380 control:0xc0 tcl:0x40 cmdlen:0 cmdpointer:0x400186 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag e Nov 13 14:04:29 nstg2 /kernel: datlen:96 data:0x1c82299c segs:0x1 segp:0x7dfdbe78 Nov 13 14:04:29 nstg2 /kernel: sg_addr:1c82299c sg_len:96 Nov 13 14:04:29 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:04:29 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 200 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0xebce399c dxfer_len: 96 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: set_trans valid: 1f period: a offset: a bus: 1 flags: d Nov 13 14:04:29 nstg2 /kernel: set_trans valid: 1f CUR period: 0 offset: 0 bus: 0 flags: 5 Nov 13 14:04:29 nstg2 /kernel: dev flag: 40 inq->flags: 30 hba_inf: 32 Nov 13 14:04:29 nstg2 /kernel: dev qflags: 0 dev quirk tags: 2 Nov 13 14:04:29 nstg2 /kernel: set_trans valid: 1f period: a offset: a bus: 1 flags: 5 Nov 13 14:04:29 nstg2 /kernel: (probe0:ahc3:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf62b800) dev: cf618280 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2c00 dmatag: 0xcf62ab40 scb_data: 0xcf62b8fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7de800 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf623700 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf62d000 ccb 0xcf7de800 flags 4000 bus 7dfe0008 cnt 0 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f87000 control:0x40 tcl:0x0 cmdlen:6 cmdpointer:0x37020 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 9f 0 0 tag 0 Nov 13 14:04:29 nstg2 /kernel: datlen:0 data:0x0 segs:0x0 segp:0x0 Nov 13 14:04:29 nstg2 /kernel: sg_addr:1a922400 sg_len:255 Nov 13 14:04:29 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:04:29 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:04:29 nstg2 /kernel: rtry: 4 func: 901 stat: 200 flags: c0 pid: 3 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 1, 0 Nov 13 14:04:29 nstg2 /kernel: XPT_ACCEPT ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 0 db6d0000 6db6db6d db6db6db Nov 13 14:04:29 nstg2 /kernel: targdar putting atio(0xcf96b900) on xmit_ccb Nov 13 14:04:29 nstg2 /kernel: targdaw UIO cnt: 1 resid: 0 seg: 0 rw: 1 Nov 13 14:04:29 nstg2 /kernel: targdawrite send ACK Nov 13 14:04:29 nstg2 /kernel: ATIO 0xcf96b900, bp 0 on work Nov 13 14:04:29 nstg2 /kernel: Sending CTIO CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 1 flags: 400000c0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0 dxfer_len: 0 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: c0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 0 db6d0000 6db6db6d db6db6db Nov 13 14:04:29 nstg2 /kernel: Thawing queue c0 Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf60d000) dev: cf618480 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2800 dmatag: 0xcf62af80 scb_data: 0xcf60d0fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7c2400 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf6237b0 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[0]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: lstate[0, 0xcf91fb40]: Nov 13 14:04:29 nstg2 /kernel: path(0xcf7b7f80): accept: cf96bb00, num=49 Nov 13 14:04:29 nstg2 /kernel: immed: cf96e600, num=50 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf6281c0 ccb 0xcf7c2400 flags 4000 bus 7dfdbe78 cnt 0 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f80380 control:0xc0 tcl:0x40 cmdlen:0 cmdpointer:0x400082 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag e Nov 13 14:04:29 nstg2 /kernel: datlen:0 data:0x0 segs:0x0 segp:0x0 Nov 13 14:04:29 nstg2 /kernel: sg_addr:1c82299c sg_len:96 Nov 13 14:04:29 nstg2 /kernel: scsi rate 93 offset 7f Nov 13 14:04:29 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 200 flags: 400000c0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0 dxfer_len: 0 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: (da1:ahc3:0:0:0): READ CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf62b800) dev: cf618280 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2c00 dmatag: 0xcf62ab40 scb_data: 0xcf62b8fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7de800 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf623700 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf62d000 ccb 0xcf7de800 flags 4000 bus 7dfe0008 cnt 1 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f87000 control:0x40 tcl:0x0 cmdlen:10 cmdpointer:0x37020 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 9f 0 0 tag 0 Nov 13 14:04:29 nstg2 /kernel: datlen:8 data:0x7ddeb3e0 segs:0x1 segp:0x7dfe0008 Nov 13 14:04:29 nstg2 /kernel: sg_addr:7ddeb3e0 sg_len:8 Nov 13 14:04:29 nstg2 /kernel: scsi rate 93 offset 7f Nov 13 14:04:29 nstg2 /kernel: cdb:25 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:04:29 nstg2 /kernel: rtry: 4 func: 901 stat: 200 flags: 40 pid: 3 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 1, 0 Nov 13 14:04:29 nstg2 /kernel: XPT_ACCEPT ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 10 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 25 0 6db60000 db6db6db Nov 13 14:04:29 nstg2 /kernel: targdar putting atio(0xcf96b900) on xmit_ccb Nov 13 14:04:29 nstg2 /kernel: targdaw UIO cnt: 1 resid: 8 seg: 0 rw: 1 Nov 13 14:04:29 nstg2 /kernel: ATIO 0xcf96b900, bp 0xdbe16158 on work Nov 13 14:04:29 nstg2 /kernel: Sending CTIO CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 1 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0xebce3420 dxfer_len: 8 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: ATIO(0xcf96b900):CCB: 0xcf96b900 Nov 13 14:04:29 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 40 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96aec0 Nov 13 14:04:29 nstg2 /kernel: cdb_len: 10 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB: 25 0 6db60000 db6db6db Nov 13 14:04:29 nstg2 /kernel: Thawing queue 40 Nov 13 14:04:29 nstg2 /kernel: AHC softc(0xcf60d000) dev: cf618480 Nov 13 14:04:29 nstg2 /kernel: tag: 0 bsh: 2800 dmatag: 0xcf62af80 scb_data: 0xcf60d0fc Nov 13 14:04:29 nstg2 /kernel: pending ccbs: 0xcf7c2400 num=1 Nov 13 14:04:29 nstg2 /kernel: sg_maps: 0xcf6237b0 num=1073741824 Nov 13 14:04:29 nstg2 /kernel: TMODE[0]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: lstate[0, 0xcf91fb40]: Nov 13 14:04:29 nstg2 /kernel: path(0xcf7b7f80): accept: cf96bb00, num=49 Nov 13 14:04:29 nstg2 /kernel: immed: cf96e600, num=50 Nov 13 14:04:29 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:04:29 nstg2 /kernel: SCB 0xcf6281c0 ccb 0xcf7c2400 flags 4000 bus 7dfdbe78 cnt 1 Nov 13 14:04:29 nstg2 /kernel: hscb:0xf1f80380 control:0xc0 tcl:0x40 cmdlen:0 cmdpointer:0x400186 Nov 13 14:04:29 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag e Nov 13 14:04:29 nstg2 /kernel: datlen:8 data:0x1c93e420 segs:0x1 segp:0x7dfdbe78 Nov 13 14:04:29 nstg2 /kernel: sg_addr:1c93e420 sg_len:8 Nov 13 14:04:29 nstg2 /kernel: scsi rate 93 offset 7f Nov 13 14:04:29 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:04:29 nstg2 /kernel: CCB: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: rtry: 2 func: 933 stat: 200 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:04:29 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:04:29 nstg2 /kernel: CSIO: 0xcf7c2400 Nov 13 14:04:29 nstg2 /kernel: next_ccb: 0x6db6db6d req_map: 0xdb6db6db data_ptr: 0xebce3420 dxfer_len: 8 Nov 13 14:04:29 nstg2 /kernel: sense_len: 18 cdb_len: 6 sglist_len: 28086 scsi_status: 0 Nov 13 14:04:29 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0xdb6db6db len: 56173 Nov 13 14:04:29 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:04:29 nstg2 /kernel: CDB_IO: ptr: 0x12 Nov 13 14:04:29 nstg2 /kernel: bytes: 12 0 0 0 24 0 b6 6d Nov 13 14:04:29 nstg2 /kernel: db b6 6d db 6d db b6 6d Nov 13 14:04:29 nstg2 /kernel: da1 at ahc3 bus 0 target 0 lun 0 Nov 13 14:04:29 nstg2 /kernel: da1: <Lucent TARG-DA 0.2> Fixed Direct Access SCSI-3 device Nov 13 14:04:29 nstg2 /kernel: ANNOC status: 1 valid: 1f period: a offset: 7f bus: 1 Nov 13 14:04:29 nstg2 /kernel: da1: 80.000MB/s transfers (40.000MHz, offset 127, 16bit) Nov 13 14:04:29 nstg2 /kernel: da1: 24MB (50464 512 byte sectors: 64H 32S/T 24C) TERMINATING USER-LEVEL PROCESS FIRST TIME Nov 13 14:04:38 nstg2 /kernel: (targda0:ahc2:0:0:0): Target mode disabled Nov 13 14:04:38 nstg2 /kernel: (noperiph:ahc2:0:0:0): RESCAN AFTER TERMINATING USER-LEVEL PROCESS FIRST TIME Nov 13 14:04:51 nstg2 /kernel: (probe0:ahc3:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 Nov 13 14:04:51 nstg2 /kernel: (probe0:ahc3:0:0:0): INQUIRY. CDB: 12 0 0 0 24 0 Nov 13 14:04:51 nstg2 /kernel: (da1:ahc3:0:0:0): lost device Nov 13 14:04:51 nstg2 /kernel: (da1:ahc3:0:0:0): removing device entry STARTING USER-LEVEL PROCESS SECOND TIME Nov 13 14:05:03 nstg2 /kernel: (targda0:ahc2:0:0:0): Lun now enabled for target mode RESCAN AFTER START USER-LEVEL PROCESS SECOND TIME Nov 13 14:05:16 nstg2 /kernel: (probe0:ahc3:0:0:0): INQUIRY. CDB: 12 0 0 0 24 0 Nov 13 14:05:16 nstg2 /kernel: AHC softc(0xcf62b800) dev: cf618280 Nov 13 14:05:19 nstg2 /kernel: tag: 0 bsh: 2c00 dmatag: 0xcf62ab40 scb_data: 0xcf62b8fc Nov 13 14:05:19 nstg2 /kernel: pending ccbs: 0xcf7c2400 num=1 Nov 13 14:05:19 nstg2 /kernel: sg_maps: 0xcf623700 num=1073741824 Nov 13 14:05:19 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:05:19 nstg2 /kernel: SCB 0xcf62d000 ccb 0xcf7c2400 flags 4000 bus 7dfe0008 cnt 1 Nov 13 14:05:19 nstg2 /kernel: hscb:0xf1f87000 control:0x40 tcl:0x0 cmdlen:6 cmdpointer:0x37020 Nov 13 14:05:19 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 9f 0 0 tag 0 Nov 13 14:05:19 nstg2 /kernel: datlen:36 data:0x7dd17884 segs:0x1 segp:0x7dfe0008 Nov 13 14:05:19 nstg2 /kernel: sg_addr:7dd17884 sg_len:36 Nov 13 14:05:19 nstg2 /kernel: scsi rate 93 offset 7f Nov 13 14:05:19 nstg2 /kernel: cdb:12 0 0 0 24 0 0 0 0 0 0 0 Nov 13 14:05:19 nstg2 /kernel: CCB: 0xcf7c2400 Nov 13 14:05:19 nstg2 /kernel: rtry: 4 func: 901 stat: 200 flags: 40 pid: 3 tid: 0 lun: 0 Nov 13 14:05:19 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:05:19 nstg2 /kernel: XPT_ACCEPT ATIO(0xcf967800):CCB: 0xcf967800 Nov 13 14:05:19 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:05:19 nstg2 /kernel: ppriv: 0, cf96adc0 Nov 13 14:05:19 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:05:19 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:05:19 nstg2 /kernel: targdar putting atio(0xcf967800) on xmit_ccb Nov 13 14:05:19 nstg2 /kernel: targdaw UIO cnt: 1 resid: 36 seg: 0 rw: 1 Nov 13 14:05:19 nstg2 /kernel: ATIO 0xcf967800, bp 0xdbe16158 on work Nov 13 14:05:19 nstg2 /kernel: Sending CTIO CCB: 0xcf7de800 Nov 13 14:05:19 nstg2 /kernel: rtry: 2 func: 933 stat: 1 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:19 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:19 nstg2 /kernel: CSIO: 0xcf7de800 Nov 13 14:05:19 nstg2 /kernel: next_ccb: 0x2030000 req_map: 0x30000020 data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:05:19 nstg2 /kernel: sense_len: 32 cdb_len: 10 sglist_len: 0 scsi_status: 0 Nov 13 14:05:19 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0 len: 0 Nov 13 14:05:19 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:05:19 nstg2 /kernel: CDB_IO: ptr: 0x25 Nov 13 14:05:19 nstg2 /kernel: bytes: 25 0 0 0 0 0 0 0 Nov 13 14:05:19 nstg2 /kernel: 0 0 0 0 0 0 0 0 Nov 13 14:05:19 nstg2 /kernel: ATIO(0xcf967800):CCB: 0xcf967800 Nov 13 14:05:19 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 40 pid: 2 tid: 0 lun: 0 Nov 13 14:05:19 nstg2 /kernel: ppriv: 0, cf96adc0 Nov 13 14:05:19 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:05:19 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:05:19 nstg2 /kernel: Thawing queue 40 Nov 13 14:05:19 nstg2 /kernel: AHC softc(0xcf60d000) dev: cf618480 Nov 13 14:05:19 nstg2 /kernel: tag: 0 bsh: 2800 dmatag: 0xcf62af80 scb_data: 0xcf60d0fc Nov 13 14:05:19 nstg2 /kernel: pending ccbs: 0xcf7de800 num=1 Nov 13 14:05:19 nstg2 /kernel: sg_maps: 0xcf6237b0 num=1073741824 Nov 13 14:05:19 nstg2 /kernel: TMODE[0]: ultra: 0 disc: ffff tag: 0 Nov 13 14:05:19 nstg2 /kernel: lstate[0, 0xcf96ae40]: Nov 13 14:05:19 nstg2 /kernel: path(0xcf7b76a0): accept: cf967a00, num=49 Nov 13 14:05:19 nstg2 /kernel: immed: cf96e300, num=50 Nov 13 14:05:19 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:05:19 nstg2 /kernel: SCB 0xcf6281c0 ccb 0xcf7de800 flags 4000 bus 7dfdbe78 cnt 1 Nov 13 14:05:19 nstg2 /kernel: hscb:0xf1f80380 control:0xc0 tcl:0x40 cmdlen:0 cmdpointer:0x400186 Nov 13 14:05:19 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag e Nov 13 14:05:19 nstg2 /kernel: datlen:36 data:0x1c94699c segs:0x1 segp:0x7dfdbe78 Nov 13 14:05:19 nstg2 /kernel: sg_addr:1c94699c sg_len:36 Nov 13 14:05:19 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:05:19 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:05:19 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:05:19 nstg2 /kernel: rtry: 2 func: 933 stat: 200 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:19 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:19 nstg2 /kernel: CSIO: 0xcf7de800 Nov 13 14:05:19 nstg2 /kernel: next_ccb: 0x2030000 req_map: 0x30000020 data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:05:19 nstg2 /kernel: sense_len: 32 cdb_len: 10 sglist_len: 0 scsi_status: 0 Nov 13 14:05:19 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0 len: 0 Nov 13 14:05:19 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:05:19 nstg2 /kernel: CDB_IO: ptr: 0x25 Nov 13 14:05:19 nstg2 /kernel: bytes: 25 0 0 0 0 0 0 0 Nov 13 14:05:19 nstg2 /kernel: 0 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: (targda0:ahc2:0:0:0): SCB 0xe - timed out in Data-out phase, SEQADDR == 0xc3 Nov 13 14:05:30 nstg2 /kernel: SSTAT1 == 0x2 Nov 13 14:05:30 nstg2 /kernel: SSTAT3 == 0x0 Nov 13 14:05:30 nstg2 /kernel: SCSIPHASE == 0x0 Nov 13 14:05:30 nstg2 /kernel: SCSIRATE == 0x0 Nov 13 14:05:30 nstg2 /kernel: SCSIOFFSET == 0x0 Nov 13 14:05:30 nstg2 /kernel: SEQ_FLAGS == 0xa6 Nov 13 14:05:30 nstg2 /kernel: SCB_DATAPTR == 0x1c94699c Nov 13 14:05:30 nstg2 /kernel: SCB_DATACNT == 0x24 Nov 13 14:05:30 nstg2 /kernel: SCB_SGCOUNT == 0x1 Nov 13 14:05:30 nstg2 /kernel: CCSCBCTL == 0x0 Nov 13 14:05:30 nstg2 /kernel: CCSCBCNT == 0x0 Nov 13 14:05:30 nstg2 /kernel: DFCNTRL == 0x2c Nov 13 14:05:30 nstg2 /kernel: DFSTATUS == 0x88 Nov 13 14:05:30 nstg2 /kernel: CCHCNT == 0x0 Nov 13 14:05:30 nstg2 /kernel: sg[0] - Addr 0x1c94699c : Length 36 Nov 13 14:05:30 nstg2 /kernel: scb->flags: 4020 Nov 13 14:05:30 nstg2 /kernel: (probe0:ahc3:0:0:0): Unexpected busfree in Data-in phase Nov 13 14:05:30 nstg2 /kernel: SEQADDR == 0x5d Nov 13 14:05:30 nstg2 /kernel: targdadone ccb status not complete: 4b Nov 13 14:05:30 nstg2 /kernel: XPT_CONT_TARGET_IO incr: 36 resid: 36 bp: 0xdbe16158 Nov 13 14:05:30 nstg2 /kernel: CONT csio resid: 0 Nov 13 14:05:30 nstg2 /kernel: SOFTC state: 0 flags: 44 execptions: 0 accept_tio: 0xcf967800 Nov 13 14:05:30 nstg2 /kernel: targda_softc(0xcf921000): Nov 13 14:05:30 nstg2 /kernel: 0 cf921000 0 cf921008 Nov 13 14:05:30 nstg2 /kernel: 0 cf921010 0 cf921018 Nov 13 14:05:30 nstg2 /kernel: 0 cf921020 0 0 Nov 13 14:05:30 nstg2 /kernel: 0 0 cf921034 714017 Nov 13 14:05:30 nstg2 /kernel: 0 0 cf8d9a00 0 Nov 13 14:05:30 nstg2 /kernel: 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: 44 0 2 cf967800 Nov 13 14:05:30 nstg2 /kernel: cf96e300 0 0 0 Nov 13 14:05:30 nstg2 /kernel: 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: ATIO Nov 13 14:05:30 nstg2 /kernel: ATIO(0xcf967800):CCB: 0xcf967800 Nov 13 14:05:30 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf96adc0 Nov 13 14:05:30 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:05:30 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:05:30 nstg2 /kernel: DESCR Nov 13 14:05:30 nstg2 /kernel: descr(0xcf96adc0): atio_link: 0xcf967a00 DATA: resid=36 incr=36 size=6 Nov 13 14:05:30 nstg2 /kernel: data: 0xebce399c store: 0xcf967700 buf: 0xdbe16158 Nov 13 14:05:30 nstg2 /kernel: max=256 timeout=1388 status=0 Nov 13 14:05:30 nstg2 /kernel: DONE_CCB->CCB_H Nov 13 14:05:30 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: rtry: 2 func: 933 stat: 4b flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:30 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: rtry: 2 func: 933 stat: 4b flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:30 nstg2 /kernel: CSIO: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: next_ccb: 0x2030000 req_map: 0x30000020 data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:05:30 nstg2 /kernel: sense_len: 32 cdb_len: 10 sglist_len: 0 scsi_status: 0 Nov 13 14:05:30 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0 len: 0 Nov 13 14:05:30 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:05:30 nstg2 /kernel: CDB_IO: ptr: 0x25 Nov 13 14:05:30 nstg2 /kernel: bytes: 25 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: 0 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: descr(0xcf96adc0): atio_link: 0xcf967a00 DATA: resid=36 incr=0 size=6 Nov 13 14:05:30 nstg2 /kernel: data: 0xebce399c store: 0xcf967700 buf: 0xdbe16158 Nov 13 14:05:30 nstg2 /kernel: max=256 timeout=1388 status=0 Nov 13 14:05:30 nstg2 /kernel: count: 36 data: 0xebce399c error: 5 ioflags: 264256 resid: 36 Nov 13 14:05:30 nstg2 /kernel: Completing buffer 0xdbe16158 dres 36 biores 36 Nov 13 14:05:30 nstg2 /kernel: Returning ATIO to target Nov 13 14:05:30 nstg2 /kernel: (probe0:ahc3:0:0:0): INQUIRY. CDB: 12 0 0 0 24 0 Nov 13 14:05:30 nstg2 /kernel: AHC softc(0xcf62b800) dev: cf618280 Nov 13 14:05:30 nstg2 /kernel: tag: 0 bsh: 2c00 dmatag: 0xcf62ab40 scb_data: 0xcf62b8fc Nov 13 14:05:30 nstg2 /kernel: pending ccbs: 0xcf7c2400 num=1 Nov 13 14:05:30 nstg2 /kernel: sg_maps: 0xcf623700 num=1073741824 Nov 13 14:05:30 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:05:30 nstg2 /kernel: SCB 0xcf62d000 ccb 0xcf7c2400 flags 4000 bus 7dfe0008 cnt 1 Nov 13 14:05:30 nstg2 /kernel: hscb:0xf1f87000 control:0x40 tcl:0x0 cmdlen:6 cmdpointer:0x37020 Nov 13 14:05:30 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 9f 0 0 tag 0 Nov 13 14:05:30 nstg2 /kernel: datlen:36 data:0x7dd17884 segs:0x1 segp:0x7dfe0008 Nov 13 14:05:30 nstg2 /kernel: sg_addr:7dd17884 sg_len:36 Nov 13 14:05:30 nstg2 /kernel: scsi rate 93 offset 7f Nov 13 14:05:30 nstg2 /kernel: cdb:12 0 0 0 24 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: CCB: 0xcf7c2400 Nov 13 14:05:30 nstg2 /kernel: rtry: 3 func: 901 stat: 200 flags: 40 pid: 3 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf96b900 Nov 13 14:05:30 nstg2 /kernel: XPT_ACCEPT ATIO(0xcf967800):CCB: 0xcf967800 Nov 13 14:05:30 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf96adc0 Nov 13 14:05:30 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:05:30 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:05:30 nstg2 /kernel: targdar putting atio(0xcf967800) on xmit_ccb Nov 13 14:05:30 nstg2 /kernel: targdaw UIO cnt: 1 resid: 36 seg: 0 rw: 1 Nov 13 14:05:30 nstg2 /kernel: ATIO 0xcf967800, bp 0xdbe16158 on work Nov 13 14:05:30 nstg2 /kernel: Bad ctio status 4b vs. 0 Nov 13 14:05:30 nstg2 /kernel: Sending CTIO CCB: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: rtry: 2 func: 933 stat: 1 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:30 nstg2 /kernel: CSIO: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: next_ccb: 0x2030000 req_map: 0x30000020 data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:05:30 nstg2 /kernel: sense_len: 32 cdb_len: 10 sglist_len: 0 scsi_status: 0 Nov 13 14:05:30 nstg2 /kernel: sense_resid: 0 resid: 24 msg_ptr: 0 len: 0 Nov 13 14:05:30 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:05:30 nstg2 /kernel: CDB_IO: ptr: 0x25 Nov 13 14:05:30 nstg2 /kernel: bytes: 25 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: 0 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: ATIO(0xcf967800):CCB: 0xcf967800 Nov 13 14:05:30 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 40 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf96adc0 Nov 13 14:05:30 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:05:30 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:05:30 nstg2 /kernel: Thawing queue 40 Nov 13 14:05:30 nstg2 /kernel: AHC softc(0xcf60d000) dev: cf618480 Nov 13 14:05:30 nstg2 /kernel: tag: 0 bsh: 2800 dmatag: 0xcf62af80 scb_data: 0xcf60d0fc Nov 13 14:05:30 nstg2 /kernel: pending ccbs: 0xcf7de800 num=1 Nov 13 14:05:30 nstg2 /kernel: sg_maps: 0xcf6237b0 num=1073741824 Nov 13 14:05:30 nstg2 /kernel: TMODE[0]: ultra: 0 disc: ffff tag: 0 Nov 13 14:05:30 nstg2 /kernel: lstate[0, 0xcf96ae40]: Nov 13 14:05:30 nstg2 /kernel: path(0xcf7b76a0): accept: cf967a00, num=49 Nov 13 14:05:30 nstg2 /kernel: immed: cf96e300, num=50 Nov 13 14:05:30 nstg2 /kernel: TMODE[4]: ultra: 0 disc: ffff tag: 0 Nov 13 14:05:30 nstg2 /kernel: SCB 0xcf6281c0 ccb 0xcf7de800 flags 4000 bus 7dfdbe78 cnt 1 Nov 13 14:05:30 nstg2 /kernel: hscb:0xf1f80380 control:0xc0 tcl:0x40 cmdlen:0 cmdpointer:0x400186 Nov 13 14:05:30 nstg2 /kernel: status: 0 res SG cnt: 0 res data cnt: 0 0 0 tag e Nov 13 14:05:30 nstg2 /kernel: datlen:36 data:0x1c94699c segs:0x1 segp:0x7dfdbe78 Nov 13 14:05:30 nstg2 /kernel: sg_addr:1c94699c sg_len:36 Nov 13 14:05:30 nstg2 /kernel: scsi rate 0 offset 0 Nov 13 14:05:30 nstg2 /kernel: cdb:0 0 0 0 0 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: rtry: 2 func: 933 stat: 200 flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:30 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:30 nstg2 /kernel: CSIO: 0xcf7de800 Nov 13 14:05:30 nstg2 /kernel: next_ccb: 0x2030000 req_map: 0x30000020 data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:05:30 nstg2 /kernel: sense_len: 32 cdb_len: 10 sglist_len: 0 scsi_status: 0 Nov 13 14:05:30 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0 len: 0 Nov 13 14:05:30 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:05:30 nstg2 /kernel: CDB_IO: ptr: 0x25 Nov 13 14:05:30 nstg2 /kernel: bytes: 25 0 0 0 0 0 0 0 Nov 13 14:05:30 nstg2 /kernel: 0 0 0 0 0 0 0 0 Nov 13 14:05:41 nstg2 /kernel: (targda0:ahc2:0:0:0): SCB 0xe - timed out in Data-out phase, SEQADDR == 0xc4 Nov 13 14:05:41 nstg2 /kernel: SSTAT1 == 0x2 Nov 13 14:05:41 nstg2 /kernel: SSTAT3 == 0x0 Nov 13 14:05:41 nstg2 /kernel: SCSIPHASE == 0x0 Nov 13 14:05:41 nstg2 /kernel: SCSIRATE == 0x0 Nov 13 14:05:41 nstg2 /kernel: SCSIOFFSET == 0x0 Nov 13 14:05:41 nstg2 /kernel: SEQ_FLAGS == 0xa6 Nov 13 14:05:41 nstg2 /kernel: SCB_DATAPTR == 0x1c94699c Nov 13 14:05:41 nstg2 /kernel: SCB_DATACNT == 0x24 Nov 13 14:05:41 nstg2 /kernel: SCB_SGCOUNT == 0x1 Nov 13 14:05:41 nstg2 /kernel: CCSCBCTL == 0x0 Nov 13 14:05:41 nstg2 /kernel: CCSCBCNT == 0x0 Nov 13 14:05:41 nstg2 /kernel: DFCNTRL == 0x2c Nov 13 14:05:41 nstg2 /kernel: DFSTATUS == 0x88 Nov 13 14:05:41 nstg2 /kernel: CCHCNT == 0x0 Nov 13 14:05:41 nstg2 /kernel: sg[0] - Addr 0x1c94699c : Length 36 Nov 13 14:05:41 nstg2 /kernel: scb->flags: 4020 Nov 13 14:05:41 nstg2 /kernel: (probe0:ahc3:0:0:0): Unexpected busfree in Data-in phase Nov 13 14:05:41 nstg2 /kernel: SEQADDR == 0x5d Nov 13 14:05:41 nstg2 /kernel: targdadone ccb status not complete: 4b Nov 13 14:05:41 nstg2 /kernel: XPT_CONT_TARGET_IO incr: 36 resid: 36 bp: 0xdbe16158 Nov 13 14:05:41 nstg2 /kernel: CONT csio resid: 0 Nov 13 14:05:41 nstg2 /kernel: SOFTC state: 0 flags: 44 execptions: 0 accept_tio: 0xcf967800 Nov 13 14:05:41 nstg2 /kernel: targda_softc(0xcf921000): Nov 13 14:05:41 nstg2 /kernel: 0 cf921000 0 cf921008 Nov 13 14:05:41 nstg2 /kernel: 0 cf921010 0 cf921018 Nov 13 14:05:41 nstg2 /kernel: 0 cf921020 0 0 Nov 13 14:05:41 nstg2 /kernel: 0 0 cf921034 714017 Nov 13 14:05:41 nstg2 /kernel: 0 0 cf8d9a00 0 Nov 13 14:05:41 nstg2 /kernel: 0 0 0 0 Nov 13 14:05:41 nstg2 /kernel: 44 0 2 cf967800 Nov 13 14:05:41 nstg2 /kernel: cf96e300 0 0 0 Nov 13 14:05:41 nstg2 /kernel: 0 0 0 0 Nov 13 14:05:41 nstg2 /kernel: ATIO Nov 13 14:05:41 nstg2 /kernel: ATIO(0xcf967800):CCB: 0xcf967800 Nov 13 14:05:41 nstg2 /kernel: rtry: deadc0de func: 332 stat: 3d flags: 0 pid: 2 tid: 0 lun: 0 Nov 13 14:05:41 nstg2 /kernel: ppriv: 0, cf96adc0 Nov 13 14:05:41 nstg2 /kernel: cdb_len: 6 tag_action: 0 tag_id: 0 init_id: 4 Nov 13 14:05:41 nstg2 /kernel: CDB: 12 db6d0024 6db6db6d db6db6db Nov 13 14:05:41 nstg2 /kernel: DESCR Nov 13 14:05:41 nstg2 /kernel: descr(0xcf96adc0): atio_link: 0xcf967a00 DATA: resid=36 incr=36 size=6 Nov 13 14:05:41 nstg2 /kernel: data: 0xebce399c store: 0xcf967700 buf: 0xdbe16158 Nov 13 14:05:41 nstg2 /kernel: max=256 timeout=1388 status=0 Nov 13 14:05:41 nstg2 /kernel: DONE_CCB->CCB_H Nov 13 14:05:41 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:05:41 nstg2 /kernel: rtry: 2 func: 933 stat: 4b flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:41 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:41 nstg2 /kernel: CCB: 0xcf7de800 Nov 13 14:05:41 nstg2 /kernel: rtry: 2 func: 933 stat: 4b flags: 40000040 pid: 2 tid: 0 lun: 0 Nov 13 14:05:41 nstg2 /kernel: ppriv: 0, cf967800 Nov 13 14:05:41 nstg2 /kernel: CSIO: 0xcf7de800 Nov 13 14:05:41 nstg2 /kernel: next_ccb: 0x2030000 req_map: 0x30000020 data_ptr: 0xebce399c dxfer_len: 36 Nov 13 14:05:41 nstg2 /kernel: sense_len: 32 cdb_len: 10 sglist_len: 0 scsi_status: 0 Nov 13 14:05:41 nstg2 /kernel: sense_resid: 0 resid: 0 msg_ptr: 0 len: 0 Nov 13 14:05:41 nstg2 /kernel: tag - action: 20 tag_id: 0 init_id: 4 Nov 13 14:05:41 nstg2 /kernel: CDB_IO: ptr: 0x25 Nov 13 14:05:41 nstg2 /kernel: bytes: 25 0 0 0 0 0 0 0 Nov 13 14:05:41 nstg2 /kernel: 0 0 0 0 0 0 0 0 Nov 13 14:05:41 nstg2 /kernel: descr(0xcf96adc0): atio_link: 0xcf967a00 DATA: resid=36 incr=0 size=6 Nov 13 14:05:41 nstg2 /kernel: data: 0xebce399c store: 0xcf967700 buf: 0xdbe16158 Nov 13 14:05:41 nstg2 /kernel: max=256 timeout=1388 status=0 Nov 13 14:05:41 nstg2 /kernel: count: 36 data: 0xebce399c error: 5 ioflags: 264256 resid: 36 Nov 13 14:05:41 nstg2 /kernel: Completing buffer 0xdbe16158 dres 36 biores 36 Nov 13 14:05:41 nstg2 /kernel: Returning ATIO to target THIS REPEATS FOUR MORE TIMES BEFORE THE SYSTEM GIVES UP To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-scsi" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200011141539.KAA08238>