[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

https://bugzilla.kernel.org/show_bug.cgi?id=14563


Alan <alan@lxorguk.ukuu.org.uk> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
                 CC|                            |alan@lxorguk.ukuu.org.uk
         Resolution|                            |CODE_FIX




-- 
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

https://bugzilla.kernel.org/show_bug.cgi?id=14563


Alan <alan@lxorguk.ukuu.org.uk> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED




-- 
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] New: SCSI tape driver: Spurious EIO and kernel OOPS

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563

           Summary: SCSI tape driver: Spurious EIO and kernel OOPS
           Product: IO/Storage
           Version: 2.5
    Kernel Version: 2.6.29.4, 2.6.30.3, 2.6.31.5
          Platform: All
        OS/Version: Linux
              Tree: Mainline
            Status: NEW
          Severity: high
          Priority: P1
         Component: SCSI
        AssignedTo: linux-scsi@vger.kernel.org
        ReportedBy: linux-kernel@jmbreuer.net
        Regression: No


Created an attachment (id=23702)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23702)
BUG console capture from 2.6.30.3 while writing to tape

Overview:

Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
is hit shortly thereafter.


Steps to reproduce:

Using amanda 2.6.0-p2 to perform tape backups to an HP C5683A DDS-4 tape drive;
connected to a Adaptec 29160 Ultra160 SCSI adapter / aic7892: Ultra160 Wide
Channel A, SCSI Id=7, 32/253 SCBs.


Actual results:

Amanda ALWAYS (on affected kernels, see below) complains about an EIO while
writing to the tape a few (< 1000) MB into the tape; most of the time a kernel
BUG is displayed and the system becomes unresponsive.

See attachments BUG-*.txt for a selection. Unfortunately, I could not save
readable BUG output from 2.6.31.5 due to a management console problem; if there
is great demand I can certainly reproduce the BUG output with working console
capture.


Expected results:

Amanda should correctly write to tape during backup as it does using kernels <=
2.6.27.10.


Affected versions:

The oldest kernel I tried which DOES exhibit the problem is 2.6.29.4; other
kernels exhibiting this problem are 2.6.30.3 and 2.6.31.5.


Non-affected versions:

A distribution-patched kernel based on version 2.6.23 [2.6.23-gentoo-r8] used
to work correctly since February 2008; the newest kernel I tried which did not
exhibit this problem is 2.6.27.10.

I did not try any 2.6.28 kernel.


Additional information:

See lshw-2.6.27.10.txt for a complete hardware overview; and
dmesg-2.6.27.10.txt/dmesg-2.6.29.4.txt for dmesg output on a
working/non-working kernel, respectively.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563


Joachim Breuer <linux-kernel@jmbreuer.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|SCSI tape driver: Spurious  |SCSI tape driver: Spurious
                   |EIO and kernel OOPS         |EIO and kernel BUG




-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563


Joachim Breuer <linux-kernel@jmbreuer.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Platform|All                         |x86-64




-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #6 from Kai Mäkisara <kai.makisara@kolumbus.fi>  2009-11-16 19:19:33 ---
On Mon, 9 Nov 2009, bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
,,,
> Overview:
> 
> Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
> spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
> is hit shortly thereafter.
> 

Can you try this with debugging enabled in st? (Edit st.c to
'#define DEBUG 1' and recompile the module.) This might give more 
information about the source of the EIO and the code path it uses.

...
> Amanda should correctly write to tape during backup as it does using kernels <=
> 2.6.27.10.
> 
> 
> Affected versions:
> 
> The oldest kernel I tried which DOES exhibit the problem is 2.6.29.4; other
> kernels exhibiting this problem are 2.6.30.3 and 2.6.31.5.
> 

There were major changes to the code performing the SCSI commands at 
2.6.29. The changes were mostly done by Fujita Tomonori and I added him to 
the cc list.

Kai

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[FUJITA Tomonori]

> > Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
> > spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
> > is hit shortly thereafter.
> > 
> 
> Can you try this with debugging enabled in st? (Edit st.c to
> '#define DEBUG 1' and recompile the module.) This might give more 
> information about the source of the EIO and the code path it uses.

Sorry about that bug.

Looks like that st drivers messes up memory management but the log
doesn't give enough information.

As Kai suggested, please enable the debug option and send the new log.

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[linux-kernel]

FUJITA Tomonori wrote:
>>> Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
>>> spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
>>> is hit shortly thereafter.
>>>
>> Can you try this with debugging enabled in st? (Edit st.c to
>> '#define DEBUG 1' and recompile the module.) This might give more 
>> information about the source of the EIO and the code path it uses.
> 
> Sorry about that bug.
> 
> Looks like that st drivers messes up memory management but the log
> doesn't give enough information.
> 
> As Kai suggested, please enable the debug option and send the new log.

I've attached the relevant information to
http://bugzilla.kernel.org/show_bug.cgi?id=14563

Thanks!


So long,
   Joe

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[Kai Makisara]

On Tue, 17 Nov 2009, linux-kernel@jmbreuer.net wrote:

> FUJITA Tomonori wrote:
> >>> Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
> >>> spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
> >>> is hit shortly thereafter.
> >>>
> >> Can you try this with debugging enabled in st? (Edit st.c to
> >> '#define DEBUG 1' and recompile the module.) This might give more 
> >> information about the source of the EIO and the code path it uses.
> > 
> > Sorry about that bug.
> > 
> > Looks like that st drivers messes up memory management but the log
> > doesn't give enough information.
> > 
> > As Kai suggested, please enable the debug option and send the new log.
> 
> I've attached the relevant information to
> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
Thanks for the logs. I was hoping that they would show why that EIO 
happens. However, they do give other probably useful information.

I don't have enough energy tonight to experiment (sleep deprived ;-) but I 
have looked at the output and may have found something. The buffer size 
516096 B = 504 kB = 126 * 4096 looks suspicious, especially with 512 kB 
fixed blocks. In this case the buffer should be at least one block. This 
is given to enlarge_buffer() as argument.

Looking at enlarge_buffer(), it seems to me that if the allocation loop 
near the end fails with segs < max_segs before got > new_size, we have a 
bug: the allocation actually fails but it is returned as success. However, 
I don't have any explanation why this would happen.

I will continue tomorrow (after work).

Kai

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[Kai Makisara]

On Tue, 17 Nov 2009, Kai Makisara wrote:

> On Tue, 17 Nov 2009, linux-kernel@jmbreuer.net wrote:
> 
> > FUJITA Tomonori wrote:
> > >>> Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
> > >>> spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
> > >>> is hit shortly thereafter.
> > >>>
...
> I don't have enough energy tonight to experiment (sleep deprived ;-) but I 
> have looked at the output and may have found something. The buffer size 
> 516096 B = 504 kB = 126 * 4096 looks suspicious, especially with 512 kB 
> fixed blocks. In this case the buffer should be at least one block. This 
> is given to enlarge_buffer() as argument.
> 
> Looking at enlarge_buffer(), it seems to me that if the allocation loop 
> near the end fails with segs < max_segs before got > new_size, we have a 
> bug: the allocation actually fails but it is returned as success. However, 
> I don't have any explanation why this would happen.
> 
> I will continue tomorrow (after work).
> 
OK, I have continued but not found the bug. I have also read the other 
messages from today. The problem seems to be related to direct i/o.

The logs from the problem case gives some information about what is 
happening. This is from the log with variable block size:

st0: Number of r/w requests 86, dio used in 1, pages 128.                                                    
st0: Block limits 1 - 16777215 bytes.                                                                        
st0: Mode sense. Length 11, medium 0, WBS 10, BLL 8
st0: Density 26, tape length: 0, drv buffer: 1
st0: Block size: 0, buffer size: 516096 (1 blocks).

The first line is from closing the file. It shows that, in this case, 
direct i/o was used in one write and the other ones have, for some reason, 
used the internal buffer. The aic7xxx driver supports 128 scatter/gather 
segments and so it is capable of using direct i/o up to 512 kB. It has 
gone to using buffer for some other reason (alignment?).

The following lines are from the next open. The buffer is (should be) 
deallocated at close() (normalize_buffer() called) but, in this case, 
something is wrong.

I have hacked the sym53c8xxx driver to support 128 s/g segments, enabled 
debugging in st, and added a printk to enlarge_buffer() showing the 
requested sizes. With dd, direct i/o is used for all writes, as expected.

Most of the evening I have been fighting with amanda to get it doing 
something. Now it works to some extent. Here is an excerpt from dmesg:

[ 8927.186369] st0: Rewinding tape.
[ 8927.304694] st: enlarge_buffer(524288)
[ 8927.339866] st0: Number of r/w requests 1, dio used in 0, pages 0.
[ 8927.882000] st: enlarge_buffer(4096)
[ 8927.882906] st0: Block limits 1 - 16777215 bytes.
[ 8927.883530] st0: Mode sense. Length 11, medium 0, WBS 10, BLL 8
[ 8927.883539] st0: Density 26, tape length: 0, drv buffer: 1
[ 8927.883547] st0: Block size: 0, buffer size: 4096 (1 blocks).
[ 8927.883560] st0: No op on tape.
[ 8927.883567] st0: Rewinding tape.
[ 8927.890818] st: enlarge_buffer(524288)
[ 8927.926274] st0: Rewinding tape.
[ 8927.928806] st0: Rewinding tape.
[ 8927.959196] st0: Writing 1 filemarks.
[ 8964.922501] st0: Writing 1 filemarks.
[ 8967.184606] st0: Rewinding tape.
[ 8977.137173] st0: Number of r/w requests 182, dio used in 4, pages 512.
[ 9033.379568] st0: Block limits 1 - 16777215 bytes.
[ 9033.380174] st0: Mode sense. Length 11, medium 0, WBS 10, BLL 8
[ 9033.380179] st0: Density 26, tape length: 0, drv buffer: 1
[ 9033.380184] st0: Block size: 0, buffer size: 516096 (1 blocks).
[ 9033.380196] st0: No op on tape.

This shows that st has requested the 512 kB buffer. In the first case the 
buffer has been deallocated properly. In the second case, the buffer size 
is left at 516096. Something bad probably happens before this. One 
difference there is that in the first case the buffer has been used for 
all writes. In the second case the buffer is allocated after four direct 
writes.

Further experimentation has to wait for tomorrow.

Kai

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[FUJITA Tomonori]

On Wed, 18 Nov 2009 23:55:10 +0200 (EET)
Kai Makisara <Kai.Makisara@kolumbus.fi> wrote:

> On Tue, 17 Nov 2009, Kai Makisara wrote:
> 
> > On Tue, 17 Nov 2009, linux-kernel@jmbreuer.net wrote:
> > 
> > > FUJITA Tomonori wrote:
> > > >>> Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
> > > >>> spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
> > > >>> is hit shortly thereafter.
> > > >>>
> ...
> > I don't have enough energy tonight to experiment (sleep deprived ;-) but I 
> > have looked at the output and may have found something. The buffer size 
> > 516096 B = 504 kB = 126 * 4096 looks suspicious, especially with 512 kB 
> > fixed blocks. In this case the buffer should be at least one block. This 
> > is given to enlarge_buffer() as argument.
> > 
> > Looking at enlarge_buffer(), it seems to me that if the allocation loop 
> > near the end fails with segs < max_segs before got > new_size, we have a 
> > bug: the allocation actually fails but it is returned as success. However, 
> > I don't have any explanation why this would happen.
> > 
> > I will continue tomorrow (after work).
> > 
> OK, I have continued but not found the bug. I have also read the other 
> messages from today. The problem seems to be related to direct i/o.
> 
> The logs from the problem case gives some information about what is 
> happening. This is from the log with variable block size:
> 
> st0: Number of r/w requests 86, dio used in 1, pages 128.                                                    
> st0: Block limits 1 - 16777215 bytes.                                                                        
> st0: Mode sense. Length 11, medium 0, WBS 10, BLL 8
> st0: Density 26, tape length: 0, drv buffer: 1
> st0: Block size: 0, buffer size: 516096 (1 blocks).
> 
> The first line is from closing the file. It shows that, in this case, 
> direct i/o was used in one write and the other ones have, for some reason, 
> used the internal buffer. The aic7xxx driver supports 128 scatter/gather 
> segments and so it is capable of using direct i/o up to 512 kB. It has 
> gone to using buffer for some other reason (alignment?).
> 
> The following lines are from the next open. The buffer is (should be) 
> deallocated at close() (normalize_buffer() called) but, in this case, 
> something is wrong.

As you suggested earlier, looks like normalize_buffer() doesn't free
all the buffers. I think that I found one bug that causes to this.

When enlarge_buffer() allocates 524288 from 0, st uses six-order page
allocation. So mdata->page_order is 6 and frp_seg is 2.

After that, if st uses dio, sgl_map_user_pages() sets
mdata->page_order to 0 for st_do_scsi(). After that, when we call
normalize_buffer(), it frees only free frp_seg * PAGE_SIZE (2 * 4096)
though we should free frp_seg * PAGE_SIZE << 6 (2 * 4096 << 6). So we
see buffer_size is set to 516096 (524288 - 8192).

Here's a fix for this.

Thanks,

diff --git a/drivers/scsi/st.c b/drivers/scsi/st.c
index 12d58a7..9c44828 100644
--- a/drivers/scsi/st.c
+++ b/drivers/scsi/st.c
@@ -552,13 +552,15 @@ st_do_scsi(struct st_request * SRpnt, struct scsi_tape * STp, unsigned char *cmd
 	SRpnt->waiting = waiting;
 
 	if (STp->buffer->do_dio) {
+		mdata->page_order = 0;
 		mdata->nr_entries = STp->buffer->sg_segs;
 		mdata->pages = STp->buffer->mapped_pages;
 	} else {
+		mdata->page_order = STp->buffer->reserved_page_order;
 		mdata->nr_entries =
 			DIV_ROUND_UP(bytes, PAGE_SIZE << mdata->page_order);
-		STp->buffer->map_data.pages = STp->buffer->reserved_pages;
-		STp->buffer->map_data.offset = 0;
+		mdata->pages = STp->buffer->reserved_pages;
+		mdata->offset = 0;
 	}
 
 	memcpy(SRpnt->cmd, cmd, sizeof(SRpnt->cmd));
@@ -3699,6 +3701,9 @@ static int enlarge_buffer(struct st_buffer * STbuffer, int new_size, int need_dm
 	int segs, nbr, max_segs, b_size, order, got;
 	gfp_t priority;
 
+	DEB(printk("%s: %d %u %d\n", __func__, new_size, STbuffer->buffer_size,
+		   STbuffer->reserved_page_order);)
+
 	if (new_size <= STbuffer->buffer_size)
 		return 1;
 
@@ -3718,7 +3723,7 @@ static int enlarge_buffer(struct st_buffer * STbuffer, int new_size, int need_dm
 		priority |= __GFP_ZERO;
 
 	if (STbuffer->frp_segs) {
-		order = STbuffer->map_data.page_order;
+		order = STbuffer->reserved_page_order;
 		b_size = PAGE_SIZE << order;
 	} else {
 		for (b_size = PAGE_SIZE, order = 0;
@@ -3751,7 +3756,9 @@ static int enlarge_buffer(struct st_buffer * STbuffer, int new_size, int need_dm
 		segs++;
 	}
 	STbuffer->b_data = page_address(STbuffer->reserved_pages[0]);
-	STbuffer->map_data.page_order = order;
+	STbuffer->reserved_page_order = order;
+
+	DEB(printk("%s: %d %u %d\n", __func__, new_size, STbuffer->buffer_size,	order);)
 
 	return 1;
 }
@@ -3764,7 +3771,7 @@ static void clear_buffer(struct st_buffer * st_bp)
 
 	for (i=0; i < st_bp->frp_segs; i++)
 		memset(page_address(st_bp->reserved_pages[i]), 0,
-		       PAGE_SIZE << st_bp->map_data.page_order);
+		       PAGE_SIZE << st_bp->reserved_page_order);
 	st_bp->cleared = 1;
 }
 
@@ -3772,7 +3779,7 @@ static void clear_buffer(struct st_buffer * st_bp)
 /* Release the extra buffer */
 static void normalize_buffer(struct st_buffer * STbuffer)
 {
-	int i, order = STbuffer->map_data.page_order;
+	int i, order = STbuffer->reserved_page_order;
 
 	for (i = 0; i < STbuffer->frp_segs; i++) {
 		__free_pages(STbuffer->reserved_pages[i], order);
@@ -3780,8 +3787,11 @@ static void normalize_buffer(struct st_buffer * STbuffer)
 	}
 	STbuffer->frp_segs = 0;
 	STbuffer->sg_segs = 0;
-	STbuffer->map_data.page_order = 0;
+	STbuffer->reserved_page_order = 0;
 	STbuffer->map_data.offset = 0;
+
+	if (STbuffer->buffer_size)
+		printk(KERN_ERR "%s: %u\n", __func__, STbuffer->buffer_size);
 }
 
 
@@ -3790,7 +3800,7 @@ static void normalize_buffer(struct st_buffer * STbuffer)
 static int append_to_buffer(const char __user *ubp, struct st_buffer * st_bp, int do_count)
 {
 	int i, cnt, res, offset;
-	int length = PAGE_SIZE << st_bp->map_data.page_order;
+	int length = PAGE_SIZE << st_bp->reserved_page_order;
 
 	for (i = 0, offset = st_bp->buffer_bytes;
 	     i < st_bp->frp_segs && offset >= length; i++)
@@ -3822,7 +3832,7 @@ static int append_to_buffer(const char __user *ubp, struct st_buffer * st_bp, in
 static int from_buffer(struct st_buffer * st_bp, char __user *ubp, int do_count)
 {
 	int i, cnt, res, offset;
-	int length = PAGE_SIZE << st_bp->map_data.page_order;
+	int length = PAGE_SIZE << st_bp->reserved_page_order;
 
 	for (i = 0, offset = st_bp->read_pointer;
 	     i < st_bp->frp_segs && offset >= length; i++)
@@ -3855,7 +3865,7 @@ static void move_buffer_data(struct st_buffer * st_bp, int offset)
 {
 	int src_seg, dst_seg, src_offset = 0, dst_offset;
 	int count, total;
-	int length = PAGE_SIZE << st_bp->map_data.page_order;
+	int length = PAGE_SIZE << st_bp->reserved_page_order;
 
 	if (offset == 0)
 		return;
@@ -4577,7 +4587,6 @@ static int sgl_map_user_pages(struct st_buffer *STbp,
         }
 
 	mdata->offset = uaddr & ~PAGE_MASK;
-	mdata->page_order = 0;
 	STbp->mapped_pages = pages;
 
 	return nr_pages;
diff --git a/drivers/scsi/st.h b/drivers/scsi/st.h
index 544dc6b..f91a67c 100644
--- a/drivers/scsi/st.h
+++ b/drivers/scsi/st.h
@@ -46,6 +46,7 @@ struct st_buffer {
 	struct st_request *last_SRpnt;
 	struct st_cmdstatus cmdstat;
 	struct page **reserved_pages;
+	int reserved_page_order;
 	struct page **mapped_pages;
 	struct rq_map_data map_data;
 	unsigned char *b_data;

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[Kai Makisara]

On Thu, 19 Nov 2009, FUJITA Tomonori wrote:

...
> As you suggested earlier, looks like normalize_buffer() doesn't free
> all the buffers. I think that I found one bug that causes to this.
> 
> When enlarge_buffer() allocates 524288 from 0, st uses six-order page
> allocation. So mdata->page_order is 6 and frp_seg is 2.
> 
> After that, if st uses dio, sgl_map_user_pages() sets
> mdata->page_order to 0 for st_do_scsi(). After that, when we call
> normalize_buffer(), it frees only free frp_seg * PAGE_SIZE (2 * 4096)
> though we should free frp_seg * PAGE_SIZE << 6 (2 * 4096 << 6). So we
> see buffer_size is set to 516096 (524288 - 8192).
> 
This surely can cause problems later.

> Here's a fix for this.
> 

I have tested the patch. Amanda did make the backup without problems. 
However, looking at dmesg revealed that this time it did not use dio with 
any write. Then I made a small program that writes both with and without 
dio (when the write buffer is not aligned at page boundary, it needs 129 
s/g segments and dio is not used). Dmesg showed that dio was used in half 
of the writes and the buffer was shrunk properly.

Thanks,
Kai

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #7 from Anonymous Emailer <anonymous@kernel-bugs.osdl.org>  2009-11-17 05:15:02 ---
Reply-To: fujita.tomonori@lab.ntt.co.jp

> > Performing tape backups using amanda 2.6.0-p2 [using 512kB block size] leads to
> > spurious 'EIO' errors when writing to the tape; most of the time a kernel BUG
> > is hit shortly thereafter.
> > 
> 
> Can you try this with debugging enabled in st? (Edit st.c to
> '#define DEBUG 1' and recompile the module.) This might give more 
> information about the source of the EIO and the code path it uses.

Sorry about that bug.

Looks like that st drivers messes up memory management but the log
doesn't give enough information.

As Kai suggested, please enable the debug option and send the new log.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #8 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-17 10:56:33 ---
I've recreated the problem in 2.6.30.3 with '#define DEBUG 1' in st.c.

Attached is the console log with a few annotations interspersed:
st-debug-2.6.30.3-mtblk0.txt.

The buffer sizes of 4096 and 516096 look most suspicious to me, as amanda uses
512kB (== 524288 bytes) blocks. I tried again with 'mt setblk 524288', but the
same result: EIO followed by BUG. The corresponding console log is attached as
st-debug-2.6.30.3-mtblk512k.txt.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[FUJITA Tomonori]

On Tue, 17 Nov 2009 10:56:36 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #8 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-17 10:56:33 ---
> I've recreated the problem in 2.6.30.3 with '#define DEBUG 1' in st.c.
> 
> Attached is the console log with a few annotations interspersed:
> st-debug-2.6.30.3-mtblk0.txt.

Thanks for the logs.

> The buffer sizes of 4096 and 516096 look most suspicious to me, as amanda uses
> 512kB (== 524288 bytes) blocks.

Can you get the log with a working kernel (2.6.27?) and '#define DEBUG
1' in st.c? Then we could see what are different with the same
commands.


> I tried again with 'mt setblk 524288', but the
> same result: EIO followed by BUG. The corresponding console log is attached as
> st-debug-2.6.30.3-mtblk512k.txt.

Looks like that the kernel crashes in both logs right after dio
transfer? What happens with the kernel module parameter 'try_rdio = 0
try_wdio=0'?

Thanks,

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #9 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-17 10:57:30 ---
Created an attachment (id=23814)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23814)
Console output with st DEBUG enabled, 2.6.30.3, variable tape block size

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #10 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-17 10:57:52 ---
Created an attachment (id=23815)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23815)
Console output with st DEBUG enabled, 2.6.30.3, fixed tape block size 512k

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #11 from Anonymous Emailer <anonymous@kernel-bugs.osdl.org>  2009-11-18 09:18:05 ---
Reply-To: fujita.tomonori@lab.ntt.co.jp

On Tue, 17 Nov 2009 10:56:36 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #8 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-17 10:56:33 ---
> I've recreated the problem in 2.6.30.3 with '#define DEBUG 1' in st.c.
> 
> Attached is the console log with a few annotations interspersed:
> st-debug-2.6.30.3-mtblk0.txt.

Thanks for the logs.

> The buffer sizes of 4096 and 516096 look most suspicious to me, as amanda uses
> 512kB (== 524288 bytes) blocks.

Can you get the log with a working kernel (2.6.27?) and '#define DEBUG
1' in st.c? Then we could see what are different with the same
commands.


> I tried again with 'mt setblk 524288', but the
> same result: EIO followed by BUG. The corresponding console log is attached as
> st-debug-2.6.30.3-mtblk512k.txt.

Looks like that the kernel crashes in both logs right after dio
transfer? What happens with the kernel module parameter 'try_rdio = 0
try_wdio=0'?

Thanks,

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #12 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 15:37:50 ---
I'll attach the console log of a working dump to tape (roughly 11 GB in several
(tape) files) below.

After that, I'll try with 'try_rdi0=0 try_wdio=0'.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #13 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 15:38:25 ---
Created an attachment (id=23824)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23824)
 Console output with st DEBUG enabled, 2.6.27.10, fixed tape block size 512k

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #14 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 15:39:44 ---
Ah sorry typo, I'll of course try with 'try_rdio=0 try_wdio=0'.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #15 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 16:53:53 ---
Allright! You hit something on the head!

With 'try_rdio=0 try_wdio=0' as parameters to the st module, writing to tape
from amanda works correctly in 2.6.30.3.

I'll attach the console log.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[FUJITA Tomonori]

On Wed, 18 Nov 2009 16:53:53 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #15 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 16:53:53 ---
> Allright! You hit something on the head!
> 
> With 'try_rdio=0 try_wdio=0' as parameters to the st module, writing to tape
> from amanda works correctly in 2.6.30.3.

Thanks a lot for the logs. They are very helpful.

I think that I found one bug about dio. There might be other bugs that
cause this issue though.

Can you try the patch that I've just sent.

Thanks,

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #16 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 16:54:44 ---
Created an attachment (id=23826)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23826)
 Console output with st DEBUG enabled, 2.6.30.3, fixed tape block size 512k,
DIO turned off (see comment)

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #17 from Anonymous Emailer <anonymous@kernel-bugs.osdl.org>  2009-11-19 07:51:05 ---
Reply-To: fujita.tomonori@lab.ntt.co.jp

On Wed, 18 Nov 2009 16:53:53 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #15 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-18 16:53:53 ---
> Allright! You hit something on the head!
> 
> With 'try_rdio=0 try_wdio=0' as parameters to the st module, writing to tape
> from amanda works correctly in 2.6.30.3.

Thanks a lot for the logs. They are very helpful.

I think that I found one bug about dio. There might be other bugs that
cause this issue though.

Can you try the patch that I've just sent.

Thanks,

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #18 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-23 12:10:04 ---
Created an attachment (id=23877)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
Console output, 2.6.30.3, fixed tape block size 512k, patch by FUJITA Tomonori
2009-11-19

The patch you sent changes the behavior: I still get the EIO after (in this
case) 239 I/O requests while writing to the tape; but the machine no longer
hard-crashes with a BUG.

[I've removed the try_rdio=0/try_wdio=0 module parameters for this test.]

Attached is the console log as usual with my comments interspersed; if I read
this correctly "st0: Number of r/w requests 239, dio used in 1, pages 128."
direct I/O is used at least once before the problem occurs.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[Kai Makisara]

On Mon, 23 Nov 2009, bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #18 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-23 12:10:04 ---
> Created an attachment (id=23877)
>  --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
> Console output, 2.6.30.3, fixed tape block size 512k, patch by FUJITA Tomonori
> 2009-11-19
> 
> The patch you sent changes the behavior: I still get the EIO after (in this
> case) 239 I/O requests while writing to the tape; but the machine no longer
> hard-crashes with a BUG.
> 
> [I've removed the try_rdio=0/try_wdio=0 module parameters for this test.]
> 
> Attached is the console log as usual with my comments interspersed; if I read
> this correctly "st0: Number of r/w requests 239, dio used in 1, pages 128."
> direct I/O is used at least once before the problem occurs.
> 
Are you sure that you have used the patched st? The log does not show the 
the debugging output from Fujita's patch. It also shows the problem 
occurring before the patch:

st0: Block size: 524288, buffer size: 516096 (0 blocks).

Kai

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[FUJITA Tomonori]

On Mon, 23 Nov 2009 12:10:06 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #18 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-23 12:10:04 ---
> Created an attachment (id=23877)
>  --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
> Console output, 2.6.30.3, fixed tape block size 512k, patch by FUJITA Tomonori
> 2009-11-19
> 
> The patch you sent changes the behavior: I still get the EIO after (in this
> case) 239 I/O requests while writing to the tape; but the machine no longer
> hard-crashes with a BUG.
> 
> [I've removed the try_rdio=0/try_wdio=0 module parameters for this test.]
> 
> Attached is the console log as usual with my comments interspersed; if I read
> this correctly "st0: Number of r/w requests 239, dio used in 1, pages 128."
> direct I/O is used at least once before the problem occurs.

As Kai said, it doesn't look like a kernel log with the patch
applied. With the patch, the kernel becomes more verbose.

Can you check again?

Thanks,

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #19 from Kai Mäkisara <kai.makisara@kolumbus.fi>  2009-11-23 20:12:38 ---
On Mon, 23 Nov 2009, bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #18 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-23 12:10:04 ---
> Created an attachment (id=23877)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
>  --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
> Console output, 2.6.30.3, fixed tape block size 512k, patch by FUJITA Tomonori
> 2009-11-19
> 
> The patch you sent changes the behavior: I still get the EIO after (in this
> case) 239 I/O requests while writing to the tape; but the machine no longer
> hard-crashes with a BUG.
> 
> [I've removed the try_rdio=0/try_wdio=0 module parameters for this test.]
> 
> Attached is the console log as usual with my comments interspersed; if I read
> this correctly "st0: Number of r/w requests 239, dio used in 1, pages 128."
> direct I/O is used at least once before the problem occurs.
> 
Are you sure that you have used the patched st? The log does not show the 
the debugging output from Fujita's patch. It also shows the problem 
occurring before the patch:

st0: Block size: 524288, buffer size: 516096 (0 blocks).

Kai

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #20 from Anonymous Emailer <anonymous@kernel-bugs.osdl.org>  2009-11-25 00:21:50 ---
Reply-To: fujita.tomonori@lab.ntt.co.jp

On Mon, 23 Nov 2009 12:10:06 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #18 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-23 12:10:04 ---
> Created an attachment (id=23877)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
>  --> (http://bugzilla.kernel.org/attachment.cgi?id=23877)
> Console output, 2.6.30.3, fixed tape block size 512k, patch by FUJITA Tomonori
> 2009-11-19
> 
> The patch you sent changes the behavior: I still get the EIO after (in this
> case) 239 I/O requests while writing to the tape; but the machine no longer
> hard-crashes with a BUG.
> 
> [I've removed the try_rdio=0/try_wdio=0 module parameters for this test.]
> 
> Attached is the console log as usual with my comments interspersed; if I read
> this correctly "st0: Number of r/w requests 239, dio used in 1, pages 128."
> direct I/O is used at least once before the problem occurs.

As Kai said, it doesn't look like a kernel log with the patch
applied. With the patch, the kernel becomes more verbose.

Can you check again?

Thanks,

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563


Joachim Breuer <linux-kernel@jmbreuer.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
  Attachment #23877|0                           |1
        is obsolete|                            |




--- Comment #21 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-25 09:47:00 ---
Created an attachment (id=23929)
 --> (http://bugzilla.kernel.org/attachment.cgi?id=23929)
Console output, 2.6.30.3, fixed tape block size 512k, patch by FUJITA Tomonori
2009-11-19, really this time

Sorry about that. Insufficient sleep, insufficient coffee :-/

Attached is the log when really, actually, using FUJITA Tomonori's patch from
2009-11-19.

The two-fold good news:

a) amflush worked correctly, no EIO, no BUG
I'll still read this tape back in for verification and post a quick comment
about the result.

b) DIO apparently was used: "st0: Number of r/w requests 38867, dio used in
138, pages 17664."

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #22 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-25 16:51:21 ---
OK, reading back the tape from #21 yields no verify errors; it seems writing
with FUJITA Tomonori's patch works correctly for me.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

Re: [Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[FUJITA Tomonori]

On Wed, 25 Nov 2009 16:51:25 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #22 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-25 16:51:21 ---
> OK, reading back the tape from #21 yields no verify errors; it seems writing
> with FUJITA Tomonori's patch works correctly for me.

Thanks a lot!

And really sorry about the bug.

[Bug 14563] SCSI tape driver: Spurious EIO and kernel BUG

[bugzilla-daemon]

http://bugzilla.kernel.org/show_bug.cgi?id=14563





--- Comment #23 from Anonymous Emailer <anonymous@kernel-bugs.osdl.org>  2009-11-26 00:27:03 ---
Reply-To: fujita.tomonori@lab.ntt.co.jp

On Wed, 25 Nov 2009 16:51:25 GMT
bugzilla-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=14563
> 
> 
> 
> 
> 
> --- Comment #22 from Joachim Breuer <linux-kernel@jmbreuer.net>  2009-11-25 16:51:21 ---
> OK, reading back the tape from #21 yields no verify errors; it seems writing
> with FUJITA Tomonori's patch works correctly for me.

Thanks a lot!

And really sorry about the bug.

-- 
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.