[WBEL-users] attempt to write beyond end of device

[Kirby C. Bohling]

On Thu, Dec 09, 2004 at 05:39:09PM -0800, Syv Ritch wrote:
> On Thu, 9 Dec 2004 18:22:12 -0600, Kirby C. Bohling wrote:
> > On Thu, Dec 09, 2004 at 02:47:34PM -0800, Syv Ritch wrote:
> >
> >> Hi,
> >>
> >> The server froze a couple of nights ago. No reaction to the
> >> keyboard, but the scroll lock, num lock and caps lock keys
> >> where flashing.
> >>
> >> The only way to restart was to press the reset button.
> >>
> > That's a sure sign of a kernel panic (the flashing keyboard
> > lights a dead give away).
> >
> >
> >> The only error that I got in /var/log/messages was:
> >>
> >> kernel: attempt to write beyond end of drive
> >> kernel: 03:03: rw=0,want=0,limit=1541437675
> >>
> > That's a sign that you are writting beyond the end of a
> > device.  I've seen that a couple of times when a mistake was
> > made with LVM, where I had re-sized the lv to be larger and
> > extended the filesystem. Then an error happened and the new
> > size didn't get saved.  On the next reboot I got those types
> > of errors.
> >
> > (By any chance did you not cut and paste that?  I can't find
> > that exact message.  Grep'ing the kernel source for "attempt.*
> > end of" comes up with several similar messages, but not that
> > one)
> 
> Oops: Did not cut and paste, but the exact message was:
> "kernel: attempt to write beyond end of device" and not "end of drive"

Then it's at the location described below (ll_rw_blk.c).  I sure
hope the numbers are correct, as I based quite a bit of my analysis
on it.

> 
> >
> > Even when grepping for "end of", I can't even find anything
> > that looks like it could print that message.
> >
> > It sure looks like it's a typo away (device vs. drive) from
> > being an error out of:
> >
> > ./drivers/block/ll_rw_blk.c:1221
> >
> > It sure looks like that error is coming from trying to read
> > /dev/hda3 (the major:minor for hda3 is 03:03 which I'm fairly
> > sure what the 03:03 in that error message means).  According
> > to the comment in the code limit should be in units of 1024
> > byte sectors.
> >
> > If you start doing some reverse engineering, it sure looks
> > like it shouldn't have printed that error message.
> >

It sure looks to me that the conditions to the print the error
message couldn't have possibly been met given the output.

> >
> >> This looks like at the end of the backup. I have a SCSI tape
> >> AIC7xxx The tape drive is almost new [less than 6 month].
> >> Last night the same tape drive and same tape did run OK.
> >>
> >
> > It doesn't look like the error has anything to do with the
> > tape drive from the error message.
> >
> >
> >> The backup is 45 gig, the tape is 80 gig native.
> >>
> >
> > What software are you using to do the backup?  Are you in fact
> > backing up any partition that includes hda3?  Any idea how big
> > the partitions are?  What type of filesystem is on hda3.  (On
> > all of my machines, that ends up being swap /dev/hda1 is
> > /boot, /dev/hda2 is /, /dev/hda3 is swap, and /dev/hda4 is an
> > extended partition that all of the other filesystems end up
> > on).
> 
> I am just using tar w/o compression. 
> tar cvf /dev/st0 /* > /var/log/backup 2 > /var/log/backup.err

That looks mostly sane, personally, I wouldn't use "/*", I'd either
use "-C / ." or just "/".  Including the '*' means you'll have shell
expansion, and it misses dot files (it's just a bad habit to be in,
I've learned that lesson the hard way, when you mean everything in
the current directory just say ".").

However, you are writing to the filesystems that you are backing up.
Assuming something went badly wrong, you might have spewed data into
/var/log/backup or /var/log/backup.err enough to overrun the disk.
I'm not sure what tar or the shell would do in that case (what on
earth should you do when writting to stderr fails?)

> 
> and I assume that 03:03 was the time of the event, because it's 
> usually around that time the normal backup ends.
> 

Nope, the 03:03 is the string that is returned by:

"kdevname(bh->b_rdev)", I haven't bothered to track the kdevname
function down, but I'm really sure that's the major:minor, not the
time.  It's fairly standard for the kernel to print errors out that
way.  I've seen it in generic SCSI and IDE errors in logs before.

According to my reading of the output, you are attemting to read
from the block device (03:03) (major:minor).  Normally those are in
hexidecimal in the kernel, but "ls" prints them in decimal (this is
important, it's taken me on several wild goose chases before when I
forgot to do the conversion).  However, if you use ls:

$ ls -la /dev/hda3
brw-rw----    1 root     disk       3,   3 Jun  3  2004 /dev/hda3

You'll see that the 3,   3 are the major:minor in decimal (and hex).
It's attempting to read hda3 unless I'm really, really mistaken.

The odd part is that it sure looks like it's erroring out reading the
absolutely first block (the "rw=0" means read, "want=0", is the
number of the last 1K chunk of data you want to read).

If you can read C code, this is the chunk that is outputting the
error message:

    if (blk_size[major])
        minorsize = blk_size[major][MINOR(bh->b_rdev)];
    if (minorsize) {
        unsigned long maxsector = (minorsize << 1) + 1;
        unsigned long sector = bh->b_rsector;
        unsigned int count = bh->b_size >> 9;

        if (maxsector < count || maxsector - count < sector) {
            /* Yecch */
            bh->b_state &= ~(1 << BH_Dirty);

            /* This may well happen - the kernel calls bread()
               without checking the size of the device, e.g.,
               when mounting a device. */
            printk(KERN_INFO
                   "attempt to access beyond end of device\n");
            printk(KERN_INFO "%s: rw=%d, want=%ld, limit=%d\n",
                   kdevname(bh->b_rdev), rw,
                   (sector + count)>>1, minorsize);

            bh->b_end_io(bh, 0);
            return;
        }
    }

The reason I think it's so weird is  it sure looks like:

( maxsector < count ) if false, and ( maxsector - count < sector )
is false.  At least they sure look like they should be false given
the output.   Which implies the error message shouldn't be printed.

Plus, it appears to believe your hda3 drive is 1.2TB (yes I meant
Terabytes).  "limit" is really minorsize, and minorsize is in units
of 1k sectors (there's a comment in the code to that affect early
on, and the code appears to assume it in the calculations).  So, the
limit of the device is:

1541437675 * 1024 = 1578432179200 bytes
= 1280263.84 MB
= 1250.25 GB
= 1.22TB

If you read the code closely, you see that it converts everything
into 512byte sectors when doing calculations.  So unless you have
the absolute largest IDE harddrive I've ever heard of, my guess is
that this error message is largely a red herring.  Clearly something
else had gone badly wrong before this.

Finally, this isn't a reason for your kernel to panic.  That isn't a
call to panic, and it should just "return -1", EBADF or some such to
tar, which tar should respond relatively gracefully from.  There
should have been something else that got displayed with the actual
panic message (it might not have made it to disk though).

Personally, I'd memory check the computer with memtest86.  None of
this looks sane to me.  Generally, it's deep dark voodoo I won't
understand, or it's a memory problem when I see error messages that
make no sense.

Thanks,
	Kirby