Dtrace

Dtrace

The iscsit_cmd_flow.d script explores the flow of SCSI command through iscsit and IDM. It also traces the arguments to specific functions and their return values.   

Here is an snippet of the dtrace output for a SCSI READ command from the initiator. The trace below shows the receipt of the Control_Notify operational primitive, the allocation of a task in response to the primitive, the transmission of the Data-In PDU, the buffer callback upon data transfer completion, the transmission of the SCSI Response and finally the deallocation of the task.   

    0  -> idm~_pdu~_rx
    0    -> idm~_pdu~_rx~_forward~_ffm
    0      -> iscsit~_op~_scsi~_cmd
    0        -> iscsit~_op~_scsi~_cmd~_immed
    0          -> iscsit~_task~_alloc
    0            -> idm~_task~_alloc
    0              -> idm~_task~_constructor
    0              <- idm~_task~_constructor
    0              -> idm~_conn~_hold~_impl
    0              <- idm~_conn~_hold~_impl
    0            <- idm~_task~_alloc
    0          <- iscsit~_task~_alloc
    0          -> iscsit~_set~_cmdsn
    0          <- iscsit~_set~_cmdsn
    0          -> iscsit~_op~_scsi~_cmd~_common
    0            -> idm~_task~_start task[tt=1880] start
    0            <- idm~_task~_start
    0            -> idm~_pdu~_complete
    0              -> idm~_pdu~_cb
    0                -> idm~_pdu~_free pdu[ffffff014472cd30]
    0                  -> idm~_pdu~_destructor
    0                  <- idm~_pdu~_destructor
    0                <- idm~_pdu~_free
    0              <- idm~_pdu~_cb
    0            <- idm~_pdu~_complete
    0          <- iscsit~_op~_scsi~_cmd~_common
    0        <- iscsit~_op~_scsi~_cmd~_immed
    0      <- iscsit~_op~_scsi~_cmd
    0    <- idm~_pdu~_rx~_forward~_ffm
    0  <- idm~_pdu~_rx
    0  -> idm~_pdu~_alloc
    0    -> idm~_pdu~_constructor
    0    <- idm~_pdu~_constructor
    0   | idm~_pdu~_alloc:return pdu[ffffff014472cd30]
    0  -> idm~_sorecvhdr
    0    -> idm~_sorecv
    0      -> idm~_iov~_sorecv
    0        -> iscsit~_dbuf~_alloc
    0          -> idm~_buf~_alloc
    0            -> idm~_conn~_hold~_impl
    0            <- idm~_conn~_hold~_impl
    0          <- idm~_buf~_alloc
    0        <- iscsit~_dbuf~_alloc
    0        -> iscsit~_xfer~_scsi~_data
    0          -> idm~_buf~_tx~_to~_ini task[tt=1880], buf[buflen=16, offset=0], offset[0], xfer~_len[16]
    0            -> idm~_listbuf~_insert
    0            <- idm~_listbuf~_insert
    0            -> idm~_so~_buf~_tx~_to~_ini
    0              -> idm~_so~_send~_buf~_region task[tt=1880], opcode[25], data[ffffff0152eeba00], offset[0], xfer~_len[16]
    0                -> idm~_pdu~_alloc
    0                  -> idm~_pdu~_constructor
    0                  <- idm~_pdu~_constructor
    0                 | idm~_pdu~_alloc:return pdu[ffffff015791e810]
    0                -> iscsit~_build~_hdr
    0                <- iscsit~_build~_hdr
    0                -> idm~_pdu~_tx pdu[ffffff015791e810, opcode=25]
    0                  -> idm~_pdu~_tx~_forward
    0                    -> idm~_so~_tx
    0                      -> idm~_iov~_sosend
    0                      <- idm~_iov~_sosend
    0                      -> idm~_pdu~_complete
    0                        -> idm~_pdu~_cb
    0                          -> idm~_pdu~_free pdu[ffffff015791e810]
    0                            -> idm~_pdu~_destructor
    0                            <- idm~_pdu~_destructor
    0                          <- idm~_pdu~_free
    0                        <- idm~_pdu~_cb
    0                      <- idm~_pdu~_complete
    0                    <- idm~_so~_tx
    0                  <- idm~_pdu~_tx~_forward
    0                <- idm~_pdu~_tx
    0              <- idm~_so~_send~_buf~_region
    0              -> iscsit~_buf~_xfer~_cb
    0                -> iscsit~_idm~_to~_stmf
    0                <- iscsit~_idm~_to~_stmf
    0              <- iscsit~_buf~_xfer~_cb
    0            <- idm~_so~_buf~_tx~_to~_ini
    0           | idm~_buf~_tx~_to~_ini:return 0
    0          -> iscsit~_idm~_to~_stmf
    0          <- iscsit~_idm~_to~_stmf
    0        <- iscsit~_xfer~_scsi~_data
    0        -> iscsit~_send~_scsi~_status task[tt=1880] status[0]
    0          -> idm~_task~_done task[tt=1880] done in 512788412301122 nsecs
    0          <- idm~_task~_done
    0          -> idm~_pdu~_alloc
    0            -> idm~_pdu~_constructor
    0            <- idm~_pdu~_constructor
    0           | idm~_pdu~_alloc:return pdu[ffffff015791e810]
    0          -> iscsit~_pdu~_tx
    0            -> iscsit~_calc~_rspsn
    0            <- iscsit~_calc~_rspsn
    0            -> idm~_pdu~_tx pdu[ffffff015791e810, opcode=21]
    0              -> idm~_pdu~_tx~_forward
    0                -> idm~_so~_tx
    0                  -> idm~_iov~_sosend
    0                  <- idm~_iov~_sosend
    0                  -> idm~_pdu~_complete
    0                    -> iscsit~_send~_status~_done
    0                      -> iscsit~_idm~_to~_stmf
    0                      <- iscsit~_idm~_to~_stmf
    0                      -> idm~_pdu~_free pdu[ffffff015791e810]
    0                        -> idm~_pdu~_destructor
    0                        <- idm~_pdu~_destructor
    0                      <- idm~_pdu~_free
    0                    <- iscsit~_send~_status~_done
    0                  <- idm~_pdu~_complete
    0                <- idm~_so~_tx
    0              <- idm~_pdu~_tx~_forward
    0            <- idm~_pdu~_tx
    0          <- iscsit~_pdu~_tx
    0        <- iscsit~_send~_scsi~_status