Re: kernel/4611: Cannot read from an atapi tape drive

[Juha Erkkila <erkkila_(_at_)_cc_(_dot_)_jyu_(_dot_)_fi>]

The following reply was made to PR kernel/4611; it has been noted by GNATS.

From: Juha Erkkila <erkkila_(_at_)_cc_(_dot_)_jyu_(_dot_)_fi>
To: Kenneth R Westerback <kwesterback_(_at_)_rogers_(_dot_)_com>
Cc: gnats_(_at_)_cvs_(_dot_)_openbsd_(_dot_)_org
Subject: Re: kernel/4611: Cannot read from an atapi tape drive
Date: Sat, 12 Nov 2005 14:47:03 +0200

 On Thu, Nov 10, 2005 at 06:39:26PM -0500, Kenneth R Westerback wrote:
 > Then please try various points along the 3.7 to 3.8 path. You are
 > the first person I've ever encountered who has an atapi tape drive.
 > Certainly no developer admits to having one. If you can narrow it
 > down to a particular change I might be able to help. 
 
 The drive still works with 3.7-current from 2005-06-24, but not from
 2005-06-25, so the commit that broke it must be this one:
 
 http://www.openbsd.org/cgi-bin/cvsweb/src/sys/scsi/st.c#rev1.48
 
 > Alternatively, running a kernel with the options
 > 
 > option	SCSIDEBUG
 > option	SCSIDEBUG_LEVEL=0xf0
 > option 	SCSIDEBUG_BUSES=0x2
 > option	SCSIDEBUG_TARGETS=0x1
 > option	SCSIDEBUG_LUNS=0x1
 > 
 > and sending me the output produced when the failure occurs would
 > help.
 
 After putting these options into a kernel built from 2005-06-25 sources,
 the output I get from the kernel as I do ``restore -i'' is this:
 
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): open: dev=0xe00 (unit 0 (of 4))
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_cmd
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_get_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling pool_get
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): returning
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_done
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): command: 0,0,0,0,0,0-[0 bytes]
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): back in cmd()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): sc_err1,err = 0x0
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_free_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling private start()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): ststart
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): mounting
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_cmd
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_get_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling pool_get
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): returning
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_done
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): command: 1b,0,0,0,1,0-[0 bytes]
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): back in cmd()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): sc_err1,err = 0x0
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_free_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling private start()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): ststart
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_cmd
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_get_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling pool_get
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): returning
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_done
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): command: 0,0,0,0,0,0-[0 bytes]
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): back in cmd()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): sc_err1,err = 0x0
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_free_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling private start()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): ststart
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_cmd
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_get_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling pool_get
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): returning
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_done
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): command: 5a,0,0,0,0,0,0,0,ff,0-[255 bytes]
 Nov 12 01:23:58 purplesea /bsd: ------------------------------
 Nov 12 01:23:58 purplesea /bsd: 000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 Nov 12 01:23:58 purplesea /bsd: 016: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 Nov 12 01:23:58 purplesea /bsd: 032: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 Nov 12 01:23:58 purplesea /bsd: 048: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 Nov 12 01:23:58 purplesea /bsd: ------------------------------
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): back in cmd()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): sc_err1,err = 0x1
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): code:0x70 valid:0 key:0x5 ili:0 eom:0 fmark:0 extra:16
 Nov 12 01:23:58 purplesea /bsd: ------------------------------
 Nov 12 01:23:58 purplesea /bsd: 000: 70 00 05 00 00 00 00 10 00 00 00 00 20 00 00 00 
 Nov 12 01:23:58 purplesea /bsd: 016: 00 00 01 03 00 00 00 00 00 00 00 00 00 00 00 00 
 Nov 12 01:23:58 purplesea /bsd: ------------------------------
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling private err_handler()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_interpret_sense returned 22
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_free_xs
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): calling private start()
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): ststart
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): scsi_mode_sense_big: page 0, error = 22
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): open complete
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): ststrategy: 32768 bytes @ blk 0
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): ststart
 Nov 12 01:23:58 purplesea /bsd: st0(atapiscsi1:0:0): closing
 
 
 The following patch fixes the problem for me (after applying, both dump
 and restore work fine):
 
 Index: scsi_base.c
 ===================================================================
 RCS file: /cvs/src/sys/scsi/scsi_base.c,v
 retrieving revision 1.87
 diff -u -p -r1.87 scsi_base.c
 --- scsi_base.c	29 Aug 2005 00:41:44 -0000	1.87
 +++ scsi_base.c	12 Nov 2005 09:36:48 -0000
 @@ -492,23 +492,21 @@ scsi_do_mode_sense(sc_link, page, buf, p
  	if (big)
  		*big = 0;
  
 -	if ((sc_link->flags & SDEV_ATAPI) == 0) {
 -		/*
 -		 * Try 6 byte mode sense request first. Some devices don't
 -		 * distinguish between 6 and 10 byte MODE SENSE commands,
 -		 * returning 6 byte data for 10 byte requests. Don't bother
 -		 * with SMS_DBD. Check returned data length to ensure that
 -		 * at least a header (3 additional bytes) is returned.
 -		 */
 -		error = scsi_mode_sense(sc_link, 0, page, &buf->headers.hdr,
 -		    sizeof(*buf), flags, 20000);
 -		if (error == 0 && buf->headers.hdr.data_length > 2) {
 -			*page_data = scsi_mode_sense_page(&buf->headers.hdr,
 -			    page_len);
 -			offset = sizeof(struct scsi_mode_header);
 -			blk_desc_len = buf->headers.hdr.blk_desc_len;
 -			goto blk_desc;
 -		}	
 +	/*
 +	 * Try 6 byte mode sense request first. Some devices don't distinguish
 +	 * between 6 and 10 byte MODE SENSE commands, returning 6 byte data for
 +	 * 10 byte requests. Don't bother with SMS_DBD. Check returned data
 +	 * length to ensure that at least a header (3 additional bytes) is
 +	 * returned.
 +	 */
 +	error = scsi_mode_sense(sc_link, 0, page, &buf->headers.hdr,
 +	    sizeof(*buf), flags, 20000);
 +	if (error == 0 && buf->headers.hdr.data_length > 2) {
 +		*page_data = scsi_mode_sense_page(&buf->headers.hdr,
 +		    page_len);
 +		offset = sizeof(struct scsi_mode_header);
 +		blk_desc_len = buf->headers.hdr.blk_desc_len;
 +		goto blk_desc;
  	}	
  
  	/*