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

[Syv Ritch]

First of all thanks for the great and wonderful help. Comments inline.


On Fri, 10 Dec 2004 02:05:41 -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:
>

The drive is 160gig. When doing a df -h it shows a size of 153Gb

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

If will go back to that location next week and will run the memtest86



--
Thanks
syv@911networks.com
When the network has to work