[stgt] [PATCH 12/15] ssc: add variable-length block read support

Mark Harvey markh794 at gmail.com
Fri Oct 31 05:20:44 CET 2008


On Mon, Oct 6, 2008 at 1:37 AM, FUJITA Tomonori
<fujita.tomonori at lab.ntt.co.jp> wrote:
> Signed-off-by: FUJITA Tomonori <fujita.tomonori at lab.ntt.co.jp>
> ---
>  usr/bs_ssc.c |   43 ++++++++++++++++++++++++++++++++++++++-----
>  1 files changed, 38 insertions(+), 5 deletions(-)
>
> diff --git a/usr/bs_ssc.c b/usr/bs_ssc.c
> index cbbca83..134c670 100644
> --- a/usr/bs_ssc.c
> +++ b/usr/bs_ssc.c
> @@ -318,13 +318,46 @@ static int space_blocks(struct scsi_cmd *cmd, int32_t count)
>        return SAM_STAT_GOOD;
>  }
>
> -/* Return error - util written */
>  static int resp_var_read(struct scsi_cmd *cmd, uint8_t *buf, uint32_t length,
> -                        int *transferfed)
> +                        int *transferred)
>  {
> -       *transferfed = 0;
> -       sense_data_build(cmd, ILLEGAL_REQUEST, ASC_INVALID_FIELD_IN_CDB);
> -       return SAM_STAT_CHECK_CONDITION;
> +       struct ssc_info *ssc = dtype_priv(cmd->dev);
> +       int ret = 0, result = SAM_STAT_GOOD;
> +
> +       length = min(length, get_unaligned_be24(&cmd->scb[2]));
> +       *transferred = 0;
> +
> +       if (length != ssc->c_blk->blk_sz) {
> +               if (ssc->c_blk->blk_type == BLK_EOD)
> +                       sense_data_build(cmd, 0x40 | BLANK_CHECK,
> +                                        NO_ADDITIONAL_SENSE);
> +               else
> +                       sense_data_build(cmd, NO_SENSE, NO_ADDITIONAL_SENSE);
> +
> +               length = min(length, ssc->c_blk->blk_sz);
> +               result = SAM_STAT_CHECK_CONDITION;
> +               scsi_set_in_resid_by_actual(cmd, length);
> +
> +               if (!length)
> +                       goto out;
> +       }
> +
> +       ret = pread(cmd->dev->fd, buf, length,
> +                   ssc->c_blk->curr + sizeof(struct blk_header));
> +       if (ret != length) {
> +               sense_data_build(cmd, MEDIUM_ERROR, ASC_READ_ERROR);
> +               result = SAM_STAT_CHECK_CONDITION;
> +               goto out;
> +       }
> +       *transferred = length;
> +
> +       ret = skip_next_header(cmd->dev);
> +       if (ret) {
> +               sense_data_build(cmd, MEDIUM_ERROR, ASC_READ_ERROR);
> +               result = SAM_STAT_CHECK_CONDITION;
> +       }
> +out:
> +       return result;
>  }
>
>  static int resp_fixed_read(struct scsi_cmd *cmd, uint8_t *buf, uint32_t length,
> --
> 1.5.6.5
>
>

First off, many thanks for completing the variable-block support.

I'm finally in a position where I found some time to test all the
improvements and am stuck with this one. I don't fully understand the
return path.

I performed a basic test by 'dd' a single 256k block to the tape
drive. I then tested what would happen if I tried to 'dd' a different
block size from the tape.

Only a 'dd if=/dev/st0 bs=256k' would return any data.

Included below is the trace I captured. Hopefully it is enough to
outline what I am seeing.
BTW: Testing on real tape drives, typically return '0+xx records out'


Any pointers as to where to start looking will be grateful.
Basically, it looks like any status except SAM_STAT_GOOD does not
return the payload.

   ============================
Write a single 256k block to tape...
# dd if=/dev/zero of=/dev/st0 bs=256k count=1
1+0 records in
1+0 records out
262144 bytes (262 kB) copied, 0.0434786 s, 6.0 MB/s

Confirm 'tape' contents contains a single 256k block..
# ./dump_tape -f /d/01/tape2
Media     : tape2
 type     : Data
Media serial number : tape2_1225355078, created Thu Oct 30 19:24:38 2008

Beginning of Tape(16): Capacity 500 MB, Blk No.: 0, prev 0, curr 0, next 1152
 Uncompressed data(2): Blk No. 1, prev 0, curr 1152,  next 263344, sz 262144
         Filemark(64): Blk No. 2, prev 1152, curr 263344,  next 263392, sz 0
      End of Data(32): Blk No. 3, prev 263344, curr 263392,  next 263392, sz 0


Now test we can read in a 256k block from the tape.
# dd if=/dev/st0 of=/tmp/block0 bs=256k count=1
1+0 records in
1+0 records out
262144 bytes (262 kB) copied, 0.00424289 s, 61.8 MB/s

Now test if we can read in a partial block (this fails returning no
data - we should have read in the 128k)
# dd if=/dev/st0 of=/tmp/block0 bs=128k count=1
dd: reading `/dev/st0': Input/output error
0+0 records in
0+0 records out
0 bytes (0 B) copied, 0.00249643 s, 0.0 kB/s

Now test if we can read in a more then a block (this fails returning
no data - we should have read in the 256k)
# dd if=/dev/st0 of=/tmp/block0 bs=512k count=1
dd: reading `/dev/st0': Input/output error
0+0 records in
0+0 records out
0 bytes (0 B) copied, 0.00705821 s, 0.0 kB/s

tgtd log trace....
Write_6:
Oct 31 07:57:16 markhdt tgtd: tape_rdwr_request(508) *** WRITE_6
count: 1, length: 262144, ret: 262144, fixed: No, ssc->blk_sz: 262144
Oct 31 07:57:16 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0
a 262144 262144
Oct 31 07:57:16 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1754) found a task 6
262144 0 0
Oct 31 07:57:16 markhdt tgtd: __cmd_done(918) 8 0x7f84f1686000 (nil) 262144 0 0
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1779) no more data
Oct 31 07:57:16 markhdt tgtd: iscsi_scsi_cmd_rx_start(1463) 1 10 0 0 0 1 7

Oct 31 07:57:16 markhdt tgtd: tape_rdwr_request(448) *** Write 1 filemark ***
Oct 31 07:57:16 markhdt tgtd: append_blk(129) B4 update     :
prev/curr/next <1152/263344/263344> type: 32, num: 2, ondisk sz: 0,
about to write 0
Oct 31 07:57:16 markhdt tgtd: append_blk(150) After update  :
prev/curr/next <1152/263344/263392> type: 64, num: 2, ondisk sz: 0
Oct 31 07:57:16 markhdt tgtd: append_blk(157) EOD blk header:
prev/curr/next <263344/263392/263392> type: 32, num: 3, ondisk sz: 0
Oct 31 07:57:16 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0 10 1 0
Oct 31 07:57:16 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1754) found a task 7 0 0 0
Oct 31 07:57:16 markhdt tgtd: __cmd_done(918) 8 (nil) (nil) 0 0 0
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1779) no more data
Oct 31 07:57:16 markhdt tgtd: iscsi_scsi_cmd_rx_start(1463) 1 1 0 0 0 1 8
Oct 31 07:57:16 markhdt tgtd: iscsi_task_queue(1408) 108 108 1
Oct 31 07:57:16 markhdt tgtd: target_cmd_queue(827) 0x63e1b0 1 2
Oct 31 07:57:16 markhdt tgtd: target_cmd_queue(846) 0x63e1b0 1 2 1
Oct 31 07:57:16 markhdt tgtd: target_cmd_queue(857) 8 1 (nil) (nil) 0 0 0 0 4
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1779) no more data
Oct 31 07:57:16 markhdt tgtd: bs_thread_worker_fn(159) got 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: tape_rdwr_request(437) **** Rewind ****
Oct 31 07:57:16 markhdt tgtd: resp_rewind(101) *** Backing store fd:
/d/01/tape2 22 22 ***
Oct 31 07:57:16 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0 1 0 0
Oct 31 07:57:16 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1754) found a task 8 0 0 0
Oct 31 07:57:16 markhdt tgtd: __cmd_done(918) 8 (nil) (nil) 0 0 0
Oct 31 07:57:16 markhdt tgtd: iscsi_task_tx_start(1779) no more data
Oct 31 07:57:17 markhdt tgtd: iscsi_scsi_cmd_rx_start(1463) 1 0 0 0 0 1 9
Oct 31 07:57:17 markhdt tgtd: iscsi_task_queue(1408) 109 109 1
Oct 31 07:57:17 markhdt tgtd: target_cmd_queue(827) 0x63e1b0 0 1
Oct 31 07:57:17 markhdt tgtd: target_cmd_queue(846) 0x63e1b0 0 1 1
Oct 31 07:57:17 markhdt tgtd: target_cmd_queue(857) 9 0 (nil) (nil) 0 0 0 0 0
Oct 31 07:57:17 markhdt tgtd: iscsi_task_tx_start(1754) found a task 9 0 0 0
Oct 31 07:57:17 markhdt tgtd: __cmd_done(918) 0 (nil) (nil) 0 0 0
Oct 31 07:57:17 markhdt tgtd: iscsi_task_tx_start(1779) no more data


Successful READ_6:
Oct 31 07:58:02 markhdt tgtd: bs_thread_worker_fn(159) got 0x63e1b0
Oct 31 07:58:02 markhdt tgtd: tape_rdwr_request(471) *** READ_6:
length 262144, count 262144, fixed block No, 1152, 0
Oct 31 07:58:02 markhdt tgtd: tape_rdwr_request(478) Executed READ_6,
Read 262144 bytes, 263344
Oct 31 07:58:02 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0
8 262144 262144
Oct 31 07:58:02 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:58:02 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:58:02 markhdt tgtd: iscsi_task_tx_start(1754) found a task
23 262144 0 0
Oct 31 07:58:02 markhdt tgtd: iscsi_data_rsp_build(971) 262144 262144
262144 8192 23
Oct 31 07:58:02 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 23
Oct 31 07:58:02 markhdt tgtd: iscsi_task_tx_start(1754) found a task
23 262144 8192 0
Oct 31 07:58:02 markhdt tgtd: iscsi_data_rsp_build(971) 253952 262144
262144 8192 23
Oct 31 07:58:02 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 23
Oct 31 07:58:02 markhdt tgtd: iscsi_task_tx_start(1754) found a task
23 262144 16384 0
Oct 31 07:58:02 markhdt tgtd: iscsi_data_rsp_build(971) 245760 262144
262144 8192 23
Oct 31 07:58:02 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 23

Oct 31 07:58:02 markhdt tgtd: bs_thread_worker_fn(159) got 0x63e1b0
Oct 31 07:58:02 markhdt tgtd: tape_rdwr_request(437) **** Rewind ****
Oct 31 07:58:02 markhdt tgtd: resp_rewind(101) *** Backing store fd:
/d/01/tape2 22 22 ***
Oct 31 07:58:02 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0 1 0 0
Oct 31 07:58:02 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:58:02 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:58:02 markhdt tgtd: iscsi_task_tx_start(1754) found a task 24 0 0 0
Oct 31 07:58:02 markhdt tgtd: __cmd_done(918) 8 (nil) (nil) 0 0 0
Oct 31 07:58:02 markhdt tgtd: iscsi_task_tx_start(1779) no more data
Oct 31 07:58:03 markhdt tgtd: iscsi_scsi_cmd_rx_start(1463) 1 0 0 0 0 1 25
Oct 31 07:58:03 markhdt tgtd: iscsi_task_queue(1408) 125 125 1
Oct 31 07:58:03 markhdt tgtd: target_cmd_queue(827) 0x63e1b0 0 1
Oct 31 07:58:03 markhdt tgtd: target_cmd_queue(846) 0x63e1b0 0 1 1
Oct 31 07:58:03 markhdt tgtd: target_cmd_queue(857) 25 0 (nil) (nil) 0 0 0 0 0
Oct 31 07:58:03 markhdt tgtd: iscsi_task_tx_start(1754) found a task 25 0 0 0
Oct 31 07:58:03 markhdt tgtd: __cmd_done(918) 0 (nil) (nil) 0 0 0




Underlength READ_6 => 128k
Oct 31 07:58:11 markhdt tgtd: bs_thread_worker_fn(159) got 0x63e1b0
Oct 31 07:58:11 markhdt tgtd: tape_rdwr_request(471) *** READ_6:
length 131072, count 131072, fixed block No, 1152, 0
Oct 31 07:58:11 markhdt tgtd: tape_rdwr_request(478) Executed READ_6,
Read 131072 bytes, 263344
Oct 31 07:58:11 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0
8 131072 131072
Oct 31 07:58:11 markhdt tgtd: tape_rdwr_request(580) io error 0x63e1b0
8 131072 131072 0, Success
Oct 31 07:58:11 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:58:11 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:58:11 markhdt tgtd: iscsi_task_tx_start(1754) found a task
2d 131072 0 0
Oct 31 07:58:11 markhdt tgtd: iscsi_data_rsp_build(971) 131072 131072
131072 8192 2d
Oct 31 07:58:11 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 2d
Oct 31 07:58:11 markhdt tgtd: iscsi_task_tx_start(1754) found a task
2d 131072 8192 0
Oct 31 07:58:11 markhdt tgtd: iscsi_data_rsp_build(971) 122880 131072
131072 8192 2d
Oct 31 07:58:11 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 2d
Oct 31 07:58:11 markhdt tgtd: iscsi_task_tx_start(1754) found a task
2d 131072 16384 0
Oct 31 07:58:11 markhdt tgtd: iscsi_data_rsp_build(971) 114688 131072
131072 8192 2d

Oct 31 07:58:11 markhdt tgtd: tape_rdwr_request(437) **** Rewind ****
Oct 31 07:58:11 markhdt tgtd: resp_rewind(101) *** Backing store fd:
/d/01/tape2 22 22 ***
Oct 31 07:58:11 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0 1 0 0
Oct 31 07:58:11 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:58:11 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:58:11 markhdt tgtd: iscsi_task_tx_start(1754) found a task 2e 0 0 0
Oct 31 07:58:11 markhdt tgtd: __cmd_done(918) 8 (nil) (nil) 0 0 0




Overlength READ_6 => 512k
Oct 31 07:58:17 markhdt tgtd: bs_thread_worker_fn(159) got 0x63e1b0
Oct 31 07:58:17 markhdt tgtd: tape_rdwr_request(471) *** READ_6:
length 524288, count 524288, fixed block No, 1152, 0
Oct 31 07:58:17 markhdt tgtd: tape_rdwr_request(478) Executed READ_6,
Read 262144 bytes, 263344
Oct 31 07:58:17 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0
8 262144 524288
Oct 31 07:58:17 markhdt tgtd: tape_rdwr_request(580) io error 0x63e1b0
8 262144 524288 0, Success
Oct 31 07:58:17 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:58:17 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:58:17 markhdt tgtd: iscsi_task_tx_start(1754) found a task
35 524288 0 0
Oct 31 07:58:17 markhdt tgtd: iscsi_data_rsp_build(971) 262144 524288
262144 8192 35
Oct 31 07:58:17 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 35
Oct 31 07:58:17 markhdt tgtd: iscsi_task_tx_start(1754) found a task
35 524288 8192 0
Oct 31 07:58:17 markhdt tgtd: iscsi_data_rsp_build(971) 253952 524288
262144 8192 35
Oct 31 07:58:17 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 35
Oct 31 07:58:17 markhdt tgtd: iscsi_task_tx_start(1754) found a task
35 524288 16384 0
Oct 31 07:58:17 markhdt tgtd: iscsi_data_rsp_build(971) 245760 524288
262144 8192 35
Oct 31 07:58:17 markhdt tgtd: iscsi_scsi_cmd_tx_done(1702) more data
or sense or bidir 35


Oct 31 07:58:17 markhdt tgtd: bs_thread_worker_fn(159) got 0x63e1b0
Oct 31 07:58:17 markhdt tgtd: tape_rdwr_request(437) **** Rewind ****
Oct 31 07:58:17 markhdt tgtd: resp_rewind(101) *** Backing store fd:
/d/01/tape2 22 22 ***
Oct 31 07:58:17 markhdt tgtd: tape_rdwr_request(574) io done 0x63e1b0 1 0 0
Oct 31 07:58:17 markhdt tgtd: bs_thread_ack_fn(82) found 0x63e1b0
Oct 31 07:58:17 markhdt tgtd: bs_thread_request_done(122) back to tgtd, 0x63e1b0
Oct 31 07:58:17 markhdt tgtd: iscsi_task_tx_start(1754) found a task 36 0 0 0
Oct 31 07:58:17 markhdt tgtd: __cmd_done(918) 8 (nil) (nil) 0 0 0
--
To unsubscribe from this list: send the line "unsubscribe stgt" in
the body of a message to majordomo at vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html



More information about the stgt mailing list