lkml.org 
[lkml]   [1997]   [Jan]   [3]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Date
SubjectVFS: brelse: Trying to free free buffer with 2.0.27
I noticed a problem with Linux 2.0.27 when I tried to read from a currently
used swap partition. When reading the complete partition with "cat /dev/hda2
> /dev/null", I get a "VFS: brelse: Trying to free free buffer" followed by
an Oops or GPF when the "cat" reaches the last few blocks of the partition.

I tested this on two different partitions on two different drives: An IDE
drive (attached to the onboard controller of the Intel Triton-chipset, PIO
mode 0) with a 41074 (512 byte-)block partition and a SCSI drive (attached
to a NCR/Symbios Logic 53C810A) with a 103950 block partition. On the IDE
drive, the problem occurs if you read at least 41073 blocks, on the SCSI
drive, 103945 blocks are enough to trigger it. This happens on a P100
machine with 24MB; I couldn't reproduce it on another one with 32MB (and
other partitions). Of course, the problem disappears on the 24MB-machine
if you do a "swapoff" on the partition.

I've attached the relevant part of my syslog (the three errors are from
three successive invocations of "cat"), ksymoops' output and the
corresponding sourcecode below. If anybody needs more information, mail
me--the bug is reproducible, so I can try out more things if you need.

Jan 3 19:11:29 gromit kernel: VFS: brelse: Trying to free free buffer
Jan 3 19:11:29 gromit kernel: general protection: 0000
Jan 3 19:11:29 gromit kernel: CPU: 0
Jan 3 19:11:29 gromit kernel: EIP: 0010:[<00126b5a>]
Jan 3 19:11:29 gromit kernel: EFLAGS: 00010286
Jan 3 19:11:29 gromit kernel: eax: 00000025 ebx: 0120dd58 ecx: ffaa0055 edx: 0063f380
Jan 3 19:11:29 gromit kernel: esi: 00000000 edi: 00000010 ebp: 00000400 esp: 01045cdc
Jan 3 19:11:29 gromit kernel: ds: 0018 es: 0018 fs: 002b gs: 002b ss: 0018
Jan 3 19:11:29 gromit kernel: Process cat (pid: 146, process nr: 18, stackpage=01045000)
Jan 3 19:11:29 gromit kernel: Stack: 0120dd58 01045e74 01045e78 00000400 015f19d4 0063f380 00000030 00126e5e
Jan 3 19:11:29 gromit kernel: 0120dd58 0120dd58 00000000 01045f74 0012b7d4 0120dd58 01117000 00000000
Jan 3 19:11:29 gromit kernel: 00001000 010118b8 00001000 00000000 00000400 00000000 00001000 00000000
Jan 3 19:11:29 gromit kernel: Call Trace: [<00126e5e>] [<0012b7d4>] [<0011a983>] [<0012c234>] [<00133d81>] [<00126536>] [<00126e5e>]
Jan 3 19:11:29 gromit kernel: [<00159c11>] [<0011cb92>] [<0015a1bd>] [<0015a1f0>] [<0015a21a>] [<00112850>] [<00112888>] [<00118377>]
Jan 3 19:11:29 gromit kernel: [<0010a9db>] [<00123ebf>] [<00123d8a>] [<0010aa52>]
Jan 3 19:11:29 gromit kernel: Code: 89 41 0c 0f b7 43 04 33 03 31 d2 f7 35 d0 08 19 00 89 d1 8b
Jan 3 19:11:43 gromit kernel: VFS: iput: trying to free free inode
Jan 3 19:11:43 gromit kernel: VFS: device 00:00, inode 0, mode=00000000
Jan 3 19:11:57 gromit kernel: VFS: brelse: Trying to free free buffer
Jan 3 19:11:57 gromit kernel: general protection: 0000
Jan 3 19:11:57 gromit kernel: CPU: 0
Jan 3 19:11:57 gromit kernel: EIP: 0010:[<00126b5a>]
Jan 3 19:11:57 gromit kernel: EFLAGS: 00010286
Jan 3 19:11:57 gromit kernel: eax: 00000025 ebx: 0120d798 ecx: ffaa0055 edx: 0063f380
Jan 3 19:11:57 gromit kernel: esi: 00000000 edi: ffffffff ebp: 00000400 esp: 01036cdc
Jan 3 19:11:57 gromit kernel: ds: 0018 es: 0018 fs: 002b gs: 002b ss: 0018
Jan 3 19:11:57 gromit kernel: Process cat (pid: 156, process nr: 18, stackpage=01036000)
Jan 3 19:11:57 gromit kernel: Stack: 0120d798 01036e74 01036e78 00000400 0139b000 0063f380 fffffffd 00126e5e
Jan 3 19:11:57 gromit kernel: 0120d798 0120d798 00000000 01036f74 0012b7d4 0120d798 01117700 00000000
Jan 3 19:11:57 gromit kernel: 00001000 010118b8 00001000 00000000 00000400 00000000 00001000 00000000
Jan 3 19:11:57 gromit kernel: Call Trace: [<00126e5e>] [<0012b7d4>] [<0011a983>] [<0015ea0e>] [<0016003d>] [<0015f5ac>] [<0016338b>]
Jan 3 19:11:57 gromit kernel: [<00160353>] [<00126e5e>] [<00159c11>] [<0011cb92>] [<0015a1bd>] [<0015a1f0>] [<0015a21a>] [<001168de>]
Jan 3 19:11:57 gromit kernel: [<00117af9>] [<00117ae8>] [<001128c4>] [<00118377>] [<00123ebf>] [<00123d8a>] [<0010aa52>]
Jan 3 19:11:57 gromit kernel: Code: 89 41 0c 0f b7 43 04 33 03 31 d2 f7 35 d0 08 19 00 89 d1 8b
Jan 3 19:12:28 gromit kernel: VFS: brelse: Trying to free free buffer
Jan 3 19:12:28 gromit kernel: Unable to handle kernel paging request at virtual address c325bbe0
Jan 3 19:12:28 gromit kernel: current->tss.cr3 = 01093000, Tr3 = 01093000
Jan 3 19:12:28 gromit kernel: *pde = 00000000
Jan 3 19:12:28 gromit kernel: Oops: 0000
Jan 3 19:12:28 gromit kernel: CPU: 0
Jan 3 19:12:28 gromit kernel: EIP: 0010:[<00126a12>]
Jan 3 19:12:28 gromit kernel: EFLAGS: 00010216
Jan 3 19:12:28 gromit kernel: eax: 000ef6ff ebx: 00000002 ecx: 001b9000 edx: 00c28af3
Jan 3 19:12:28 gromit kernel: esi: e14cf000 edi: 01088e7c ebp: 00000400 esp: 01088cdc
Jan 3 19:12:28 gromit kernel: ds: 0018 es: 0018 fs: 002b gs: 002b ss: 0018
Jan 3 19:12:28 gromit kernel: Process cat (pid: 160, process nr: 14, stackpage=01088000)
Jan 3 19:12:28 gromit kernel: Stack: 00000002 01088e74 01088e7c 00000400 00806110 006be400 00007400 00126e5e
Jan 3 19:12:28 gromit kernel: 00000002 00000002 00000000 01088f74 0012b7d4 00000002 01117ec0 00000000
Jan 3 19:12:28 gromit kernel: 00001000 010118b8 00001000 00000000 00000400 00000000 00001000 00000000
Jan 3 19:12:28 gromit kernel: Call Trace: [<00126e5e>] [<0012b7d4>] [<0011a983>] [<0012c234>] [<00133d81>] [<00126536>] [<00126e5e>]
Jan 3 19:12:28 gromit kernel: [<00159c11>] [<0011cb92>] [<00174e3f>] [<0015a1bd>] [<0015a21a>] [<00112850>] [<00112888>] [<00118377>]
Jan 3 19:12:28 gromit kernel: [<0010a9db>] [<00123ebf>] [<00123d8a>] [<0010aa52>]
Jan 3 19:12:28 gromit kernel: Code: 83 7c 91 14 01 7f 08 f7 c6 40 00 00 00 74 07 be 05 00 00 00

BTW, the "iput: trying to free free inode" probably wasn't caused by the
"cat" but by another process trying to write to disk at the same time. Looks
strange to me, nevertheless.

This is the output of ksymoops for the three errors:

>>EIP: 126b5a <_refile_buffer+196/478>
Trace: 126e5e <___brelse+22/44>
Trace: 12b7d4 <_block_read+5f0/648>
Trace: 11a983 <_put_dirty_page+bf/1f8>
Trace: 12c234 <_setup_arg_pages+ec/104>
Trace: 133d81 <_load_aout_binary+591/634>
Trace: 126536 <_getblk+3a/468>
Trace: 126e5e <___brelse+22/44>
Trace: 159c11 <_ext2_update_inode+2b1/2c0>
Trace: 11cb92 <_merge_segments+472/4e8>
Trace: 15a1bd <_ext2_lookup+81/180>
Trace: 15a1f0 <_ext2_lookup+b4/180>
Trace: 15a21a <_ext2_lookup+de/180>
Trace: 112850 <_timer_bh+b8/14c>
Trace: 112888 <_timer_bh+f0/14c>
Trace: 118377 <_do_bottom_half+3b/8c>
Trace: 10a9db <handle_bottom_half+b/20>
Trace: 123ebf <_sys_write+10f/148>
Trace: 123d8a <_sys_read+8a/b0>
Trace: 10aa52 <_system_call+52/80>

Code: 126b5a <_refile_buffer+196/478> movl %eax,0xc(%ecx)
Code: 126b5d <_refile_buffer+199/478> movzwl 0x4(%ebx),%eax
Code: 126b61 <_refile_buffer+19d/478> xorl (%ebx),%eax
Code: 126b63 <_refile_buffer+19f/478> xorl %edx,%edx
Code: 126b65 <_refile_buffer+1a1/478> divl 0x1908d0,%eax
Code: 126b6b <_refile_buffer+1a7/478> movl %edx,%ecx
Code: 126b6d <_refile_buffer+1a9/478> movl (%eax),%eax
Code: 126b6f <_refile_buffer+1ab/478> nop
Code: 126b70 <_refile_buffer+1ac/478> nop


>>EIP: 126b5a <_refile_buffer+196/478>
Trace: 126e5e <___brelse+22/44>
Trace: 12b7d4 <_block_read+5f0/648>
Trace: 11a983 <_put_dirty_page+bf/1f8>
Trace: 15ea0e <_ide_set_handler+26/2c>
Trace: 16003d <_ide_do_request+335/5f0>
Trace: 15f5ac <_read_intr>
Trace: 16338b <_make_request+3ef/4a8>
Trace: 160353 <_do_ide0_request+b/10>
Trace: 126e5e <___brelse+22/44>
Trace: 159c11 <_ext2_update_inode+2b1/2c0>
Trace: 11cb92 <_merge_segments+472/4e8>
Trace: 15a1bd <_ext2_lookup+81/180>
Trace: 15a1f0 <_ext2_lookup+b4/180>
Trace: 15a21a <_ext2_lookup+de/180>
Trace: 1168de <_send_sig+13e/148>
Trace: 117af9 <_it_real_fn+11/48>
Trace: 117af9 <_it_real_fn+11/48>
Trace: 1128c4 <_timer_bh+12c/14c>
Trace: 118377 <_do_bottom_half+3b/8c>
Trace: 123ebf <_sys_write+10f/148>
Trace: 123d8a <_sys_read+8a/b0>
Trace: 10aa52 <_system_call+52/80>

Code: 126b5a <_refile_buffer+196/478> movl %eax,0xc(%ecx)
Code: 126b5d <_refile_buffer+199/478> movzwl 0x4(%ebx),%eax
Code: 126b61 <_refile_buffer+19d/478> xorl (%ebx),%eax
Code: 126b63 <_refile_buffer+19f/478> xorl %edx,%edx
Code: 126b65 <_refile_buffer+1a1/478> divl 0x1908d0,%eax
Code: 126b6b <_refile_buffer+1a7/478> movl %edx,%ecx
Code: 126b6d <_refile_buffer+1a9/478> movl (%eax),%eax
Code: 126b6f <_refile_buffer+1ab/478> nop
Code: 126b70 <_refile_buffer+1ac/478> nop


>>EIP: 126a12 <_refile_buffer+4e/478>
Trace: 126e5e <___brelse+22/44>
Trace: 12b7d4 <_block_read+5f0/648>
Trace: 11a983 <_put_dirty_page+bf/1f8>
Trace: 12c234 <_setup_arg_pages+ec/104>
Trace: 133d81 <_load_aout_binary+591/634>
Trace: 126536 <_getblk+3a/468>
Trace: 126e5e <___brelse+22/44>
Trace: 159c11 <_ext2_update_inode+2b1/2c0>
Trace: 11cb92 <_merge_segments+472/4e8>
Trace: 174e3f <_n_tty_receive_buf+aef/b24>
Trace: 15a1bd <_ext2_lookup+81/180>
Trace: 15a21a <_ext2_lookup+de/180>
Trace: 112850 <_timer_bh+b8/14c>
Trace: 112888 <_timer_bh+f0/14c>
Trace: 118377 <_do_bottom_half+3b/8c>
Trace: 10a9db <handle_bottom_half+b/20>
Trace: 123ebf <_sys_write+10f/148>
Trace: 123d8a <_sys_read+8a/b0>
Trace: 10aa52 <_system_call+52/80>

Code: 126a12 <_refile_buffer+4e/478> cmpl $0x1,0x14(%ecx,%edx,4)
Code: 126a17 <_refile_buffer+53/478> jg 126a21 <_refile_buffer+5d/478>
Code: 126a19 <_refile_buffer+55/478> testl $0x40,%esi
Code: 126a1f <_refile_buffer+5b/478> je 126a28 <_refile_buffer+64/478>
Code: 126a21 <_refile_buffer+5d/478> movl $0x5,%esi


EIP 126b5a <_refile_buffer+196/478> corresponds to fs/buffer.c:323
(inline-function remove_from_hash_queue, called from fs/buffer.c:380,
inline-function remove_from_queues, called from fs/buffer.c:838, function
refile_buffer).

EIP: 126a12 <_refile_buffer+4e/478> corresponds to fs/buffer.c:823 (first
part).


Oh BTW, please don't ask why I want to read a swap-partition. :-)

BTW#2, please CC: all replies to me--I read this list via linux.dev.kernel,
which is a bit unreliable. :-(

Thanks for any hints,
Martin
--
/* Martin Buck E-Mail: martin-2.buck@student.uni-ulm.de */
/* Student of electrical engineering WWW: http://www.uni-ulm.de/~s_mbuck1/ */
/* University of Ulm, Germany Snail-Mail: Paukengasse 2, 89077 Ulm, Germany */
#include <disclaimer.h> /* PGP Key available MIME-Mail welcome */

\
 
 \ /
  Last update: 2005-03-22 13:38    [W:0.093 / U:0.300 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site