Re: 2.6.29 regression: ATA bus errors on resume

[Tejun Heo <htejun@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 1864 bytes --]

Sorry about the long delay.

Niel Lambrechts wrote:
> Morning Tejun,
> 
> Tejun Heo wrote:
>> Hello,
>>
>> Can you please do the followings?
>>
>> 1. Apply the attached patch, build & boot
>>   
> I chose 2.6.30-rc7...
>> 2. Trigger the problem and record dmesg
>>   
> It took 3 days and quite a few hibernate attempts ... :-)
> 
>> 3. On failed IO, the kernel will print the address of bi_endio.  Run
>>    "nm -n" on the vmlinux in the kernel build root and look up which
>>    function it is and post the dmesg and function name.
> I did not have that specific vmlinux.o file any more, but
> /boot/System.map-2.6.30-rc7-pae shows:
> c01a49fd t end_bio_bh_io_sync

So, it's coming from submit_bh()

> Hope this is sufficient to help you. Sorry if this is silly - being so
> inexperienced with the kernel - but I wondered if or why a dump_stack()
> in that debug patch would not be helpful?

The result is perfectly good and yeah dump_stack() on the issue path
would help but the problem is that block IO requests are processed
asynchronously so by the time we find out which request fail, the
requester stack is long gone.  We can either record the stack trace
with each request or trace it back one step at a time by chasing down
the completion callbacks.  The first requires more coding, so... :-)

Looks like the request gotta be coming from __breadahead().  The only
place this is used in ext4 is in __ext4_get_inode_loc().  Ah.. it also
contains the matching error message.  I still don't see how the READA
buffer reads can affect the synchronous path.  They're doing proper
exclusion via buffer lock.  Maybe they're getting merged?  Yeap, looks
like block code is merging READAs and regular READs.

Can you please try the attached patch and reproduce the problem and
report the kernel log?  Hopefully, this will be the last debug run.

Thanks.

-- 
tejun

[-- Attachment #2: bio_endio-debug2.patch --]
[-- Type: text/x-patch, Size: 1340 bytes --]

diff --git a/block/blk-core.c b/block/blk-core.c
index b06cf5c..c8b3a6f 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -155,8 +155,13 @@ static void req_bio_endio(struct request *rq, struct bio *bio,
 		if (bio_integrity(bio))
 			bio_integrity_advance(bio, nbytes);
 
-		if (bio->bi_size == 0)
+		if (bio->bi_size == 0) {
+			if (error)
+				printk("XXX %s: failing bio %p bi_rw=0x%lx with %d\n",
+				       rq->rq_disk ? rq->rq_disk->disk_name : "?",
+				       bio, bio->bi_rw, error);
 			bio_endio(bio, error);
+		}
 	} else {
 
 		/*
diff --git a/fs/bio.c b/fs/bio.c
index 24c9140..007edb9 100644
--- a/fs/bio.c
+++ b/fs/bio.c
@@ -1390,13 +1390,24 @@ void bio_check_pages_dirty(struct bio *bio)
  **/
 void bio_endio(struct bio *bio, int error)
 {
+	char name[BDEVNAME_SIZE] = "?";
+
+	if (bio->bi_bdev)
+		bdevname(bio->bi_bdev, name);
+
 	if (error)
 		clear_bit(BIO_UPTODATE, &bio->bi_flags);
-	else if (!test_bit(BIO_UPTODATE, &bio->bi_flags))
+	else if (!test_bit(BIO_UPTODATE, &bio->bi_flags)) {
+		printk("XXX %s: !uptodate on bio %p\n", name, bio);
 		error = -EIO;
+	}
 
-	if (bio->bi_end_io)
+	if (bio->bi_end_io) {
+		if (error)
+			printk("XXX %s: bio=%p error=%d bi_end_io=%p\n",
+			       name, bio, error, bio->bi_end_io);
 		bio->bi_end_io(bio, error);
+	}
 }
 
 void bio_pair_release(struct bio_pair *bp)