Skip to contentSkip to conversation

New: SCSI tape driver: Spurious EIO and kernel OOPS

Bug 14563 [email protected] 4 participants 38 messages Nov 9, 2009 – Nov 26, 2009

Subsystems (2)
lore
Share & tools
lore
#0 lore raw

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: [email protected]
        ReportedBy: [email protected]
        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.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#1 lore raw

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

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

--- Comment #1 from Joachim Breuer <[email protected]> 2009-11-09 08:29:23 --- Created an attachment (id=23703)
--> (http://bugzilla.kernel.org/attachment.cgi?id=23703)
BUG console capture from 2.6.30.3 while writing to tape

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#2 lore raw

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

In reply to [email protected]

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

--- Comment #2 from Joachim Breuer <[email protected]> 2009-11-09 08:29:45 --- Created an attachment (id=23704)
--> (http://bugzilla.kernel.org/attachment.cgi?id=23704)
BUG console capture from 2.6.30-gentoo-r5 while writing to tape

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#3 lore raw

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

In reply to [email protected]

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

--- Comment #3 from Joachim Breuer <[email protected]> 2009-11-09 08:30:20 --- Created an attachment (id=23705)
--> (http://bugzilla.kernel.org/attachment.cgi?id=23705)
Hardware overview created using lshw under 2.6.27.10

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#4 lore raw

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

In reply to [email protected]

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

--- Comment #4 from Joachim Breuer <[email protected]> 2009-11-09 08:30:55 --- Created an attachment (id=23706)
--> (http://bugzilla.kernel.org/attachment.cgi?id=23706)
dmesg output from affected kernel 2.6.29.4 (immediately after boot)

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#5 lore raw

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

In reply to [email protected]

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

--- Comment #5 from Joachim Breuer <[email protected]> 2009-11-09 08:31:33 --- Created an attachment (id=23707)
--> (http://bugzilla.kernel.org/attachment.cgi?id=23707)
dmesg output from non-affected kernel 2.6.27.10 (after a successful backup/test-restore run)

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#6 lore raw

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

In reply to [email protected]

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

Joachim Breuer <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------

            Summary|SCSI tape driver: Spurious  |SCSI tape driver: Spurious
                   |EIO and kernel OOPS         |EIO and kernel BUG
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#7 lore raw

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

In reply to [email protected]

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

Joachim Breuer <[email protected]> changed:

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

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#8 lore raw

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

In reply to [email protected]

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

--- Comment #6 from Kai Mäkisara <[email protected]> 2009-11-16 19:19:33 ---

Quoted 1 line · On Mon, 9 Nov 2009, [email protected] wrote:

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

,,,

Quoted 6 lines

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.

...

Quoted 9 lines

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

Signature · 6 lines
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 [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
#9 lore raw

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

Quoted 8 lines
Quoted 4 lines

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.

#10 lore raw

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

Quoted 8 lines · FUJITA Tomonori
Quoted 7 lines
Quoted 4 lines

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.

Quoted 6 lines

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

#11 lore raw

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

Quoted 11 lines · On Tue, 17 Nov 2009, [email protected] wrote:
Quoted 10 lines · FUJITA Tomonori
Quoted 7 lines
Quoted 4 lines

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.

Quoted 8 lines
Quoted 4 lines

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

#12 lore raw

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

Quoted 7 lines · Kai Makisara
Quoted 5 lines · On Tue, 17 Nov 2009, [email protected] wrote:
Quoted 4 lines · FUJITA Tomonori
Quoted 4 lines
Quoted 4 lines

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.

...

Quoted 6 lines

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.

Quoted 7 lines

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

#13 lore raw

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

Quoted 41 lines · On Wed, 18 Nov 2009 23:55:10 +0200 (EET) Kai Makisara…
Quoted 7 lines · Kai Makisara
Quoted 5 lines · On Tue, 17 Nov 2009, [email protected] wrote:
Quoted 4 lines · FUJITA Tomonori
Quoted 4 lines
Quoted 4 lines

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.

...

Quoted 6 lines

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.

Quoted 7 lines

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?).

Quoted 3 lines

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,

drivers/scsi/st.c +20 -11
index 12d58a7..9c44828 100644
@@ -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;
drivers/scsi/st.h +1 -0
index 544dc6b..f91a67c 100644
@@ -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;
#14 lore raw

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

On Thu, 19 Nov 2009, FUJITA Tomonori wrote:

...

Quoted 12 lines

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.

Quoted 2 lines

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

#15 lore raw
In reply to [email protected]
Quoted 1 line · On Mon, 9 Nov 2009, [email protected] wrote:

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

,,,

Quoted 6 lines

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.

...

Quoted 9 lines

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

#16 lore raw

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

In reply to [email protected]

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

--- Comment #7 from Anonymous Emailer <[email protected]> 2009-11-17 05:15:02 ---
Reply-To: [email protected]

Quoted 8 lines
Quoted 4 lines

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.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#17 lore raw

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

In reply to [email protected]

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

--- Comment #8 from Joachim Breuer <[email protected]> 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.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#18 lore raw

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

Quoted 11 lines · On Tue, 17 Nov 2009 10:56:36 GMT [email protected] wrote:

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

--- Comment #8 from Joachim Breuer <[email protected]> 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.

Quoted 2 lines

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.

Quoted 3 lines

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,

#19 lore raw

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

In reply to [email protected]

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

--- Comment #9 from Joachim Breuer <[email protected]> 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

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#20 lore raw

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

In reply to [email protected]

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

--- Comment #10 from Joachim Breuer <[email protected]> 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

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#21 lore raw

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

In reply to [email protected]

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

--- Comment #11 from Anonymous Emailer <[email protected]> 2009-11-18 09:18:05 ---
Reply-To: [email protected]

Quoted 11 lines · On Tue, 17 Nov 2009 10:56:36 GMT [email protected] wrote:

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

--- Comment #8 from Joachim Breuer <[email protected]> 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.

Quoted 2 lines

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.

Quoted 3 lines

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,

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#22 lore raw

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

In reply to [email protected]

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

--- Comment #12 from Joachim Breuer <[email protected]> 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'.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#23 lore raw

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

In reply to [email protected]

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

--- Comment #13 from Joachim Breuer <[email protected]> 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

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#24 lore raw

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

In reply to [email protected]

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

--- Comment #14 from Joachim Breuer <[email protected]> 2009-11-18 15:39:44 --- Ah sorry typo, I'll of course try with 'try_rdio=0 try_wdio=0'.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#25 lore raw

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

In reply to [email protected]

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

--- Comment #15 from Joachim Breuer <[email protected]> 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.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#26 lore raw

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

Quoted 11 lines · On Wed, 18 Nov 2009 16:53:53 GMT [email protected] wrote:

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

--- Comment #15 from Joachim Breuer <[email protected]> 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,

#27 lore raw

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

In reply to [email protected]

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

--- Comment #16 from Joachim Breuer <[email protected]> 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)

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#28 lore raw

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

In reply to [email protected]

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

--- Comment #17 from Anonymous Emailer <[email protected]> 2009-11-19 07:51:05 ---
Reply-To: [email protected]

Quoted 11 lines · On Wed, 18 Nov 2009 16:53:53 GMT [email protected] wrote:

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

--- Comment #15 from Joachim Breuer <[email protected]> 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,

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#29 lore raw

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

In reply to [email protected]

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

--- Comment #18 from Joachim Breuer <[email protected]> 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.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#30 lore raw

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

Quoted 16 lines · On Mon, 23 Nov 2009, [email protected] wrote:

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

--- Comment #18 from Joachim Breuer <[email protected]> 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.

Quoted 6 lines

[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

#31 lore raw

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

In reply to [email protected]
Quoted 16 lines · On Mon, 23 Nov 2009 12:10:06 GMT [email protected] wrote:

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

--- Comment #18 from Joachim Breuer <[email protected]> 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.

Quoted 5 lines

[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,

#32 lore raw

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

In reply to [email protected]

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

--- Comment #19 from Kai Mäkisara <[email protected]> 2009-11-23 20:12:38 ---

Quoted 8 lines · On Mon, 23 Nov 2009, [email protected] wrote:

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

--- Comment #18 from Joachim Breuer <[email protected]> 2009-11-23 12:10:04 --- Created an attachment (id=23877)

--> (http://bugzilla.kernel.org/attachment.cgi?id=23877)

Quoted 8 lines

--> (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.

Quoted 6 lines

[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

Signature · 6 lines
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 [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
#33 lore raw

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

In reply to [email protected]

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

--- Comment #20 from Anonymous Emailer <[email protected]> 2009-11-25 00:21:50 ---
Reply-To: [email protected]

Quoted 8 lines · On Mon, 23 Nov 2009 12:10:06 GMT [email protected] wrote:

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

--- Comment #18 from Joachim Breuer <[email protected]> 2009-11-23 12:10:04 --- Created an attachment (id=23877)

--> (http://bugzilla.kernel.org/attachment.cgi?id=23877)

Quoted 8 lines

--> (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.

Quoted 5 lines

[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,

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#34 lore raw

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

In reply to [email protected]

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

Joachim Breuer <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------

  Attachment #23877|0                           |1

is obsolete| |

--- Comment #21 from Joachim Breuer <[email protected]> 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."

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#35 lore raw

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

In reply to [email protected]

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

--- Comment #22 from Joachim Breuer <[email protected]> 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.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
#37 lore raw

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

In reply to [email protected]

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

--- Comment #23 from Anonymous Emailer <[email protected]> 2009-11-26 00:27:03 ---
Reply-To: [email protected]

Quoted 9 lines · On Wed, 25 Nov 2009 16:51:25 GMT [email protected] wrote:

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

--- Comment #22 from Joachim Breuer <[email protected]> 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.

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