Bug 616021

Summary: BUG blkdev_requests (Not tainted): Poison overwritten
Product: [Fedora] Fedora Reporter: Tom London <selinux>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED RAWHIDE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 14CC: anton, dougsland, gansalmon, itamar, jmoyer, jonathan, kernel-maint, madhu.chinakonda
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2010-08-03 23:22:14 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
complete /var/log/messages of run with BUG....
none
BUG spew from previous runs with "Poison overwritten" none

Description Tom London 2010-07-19 13:39:53 UTC
Created attachment 432886 [details]
complete /var/log/messages of run with BUG....

Description of problem:
Noticed this in /var/log/messages.  Running kernel-2.6.35-0.47.rc5.git2.fc14.x86_64

Jul 18 14:06:03 tlondon kernel: systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
Jul 18 14:06:03 tlondon kernel: =============================================================================
Jul 18 14:06:03 tlondon kernel: BUG blkdev_requests (Not tainted): Poison overwritten
Jul 18 14:06:03 tlondon kernel: -----------------------------------------------------------------------------
Jul 18 14:06:03 tlondon kernel:
Jul 18 14:06:03 tlondon kernel: INFO: 0xffff880131d473a0-0xffff880131d473a0. First byte 0x69 instead of 0x6b
Jul 18 14:06:03 tlondon kernel: INFO: Allocated in mempool_alloc_slab+0x15/0x17 age=24377 cpu=0 pid=741
Jul 18 14:06:03 tlondon kernel: INFO: Freed in mempool_free_slab+0x17/0x19 age=24113 cpu=0 pid=0
Jul 18 14:06:03 tlondon kernel: INFO: Slab 0xffffea00042e6750 objects=19 used=7 fp=0xffff880131d47380 flags=0x400000000040c3
Jul 18 14:06:03 tlondon kernel: INFO: Object 0xffff880131d47380 @offset=4992 fp=0xffff880131d471e0
Jul 18 14:06:03 tlondon kernel:
Jul 18 14:06:03 tlondon kernel: Bytes b4 0xffff880131d47370:  78 97 fb ff 00 00 00 00 5a 5a 5a 5a 5a 5a 5a 5a x.��....ZZZZZZZZ
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47380:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47390:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d473a0:  69 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b ikkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d473b0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d473c0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d473d0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d473e0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d473f0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47400:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47410:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47420:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47430:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47440:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47450:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47460:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47470:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47480:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d47490:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d474a0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d474b0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d474c0:  6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b kkkkkkkkkkkkkkkk
Jul 18 14:06:03 tlondon kernel:  Object 0xffff880131d474d0:  6b 6b 6b 6b 6b 6b 6b a5                         kkkkkkk�        
Jul 18 14:06:03 tlondon kernel: Redzone 0xffff880131d474d8:  bb bb bb bb bb bb bb bb                         ��������        
Jul 18 14:06:03 tlondon kernel: Padding 0xffff880131d47518:  5a 5a 5a 5a 5a 5a 5a 5a                         ZZZZZZZZ        
Jul 18 14:06:03 tlondon kernel: Pid: 401, comm: flush-253:0 Not tainted 2.6.35-0.47.rc5.git2.fc14.x86_64 #1
Jul 18 14:06:03 tlondon kernel: Call Trace:
Jul 18 14:06:03 tlondon kernel: [<ffffffff81118470>] print_trailer+0x133/0x13c
Jul 18 14:06:03 tlondon kernel: [<ffffffff81118910>] check_bytes_and_report+0xc1/0xff
Jul 18 14:06:03 tlondon kernel: [<ffffffff8111949c>] check_object+0xcb/0x1b4
Jul 18 14:06:03 tlondon kernel: [<ffffffff8111a887>] __slab_alloc+0x30a/0x3d5
Jul 18 14:06:03 tlondon kernel: [<ffffffff810e5933>] ? mempool_alloc_slab+0x15/0x17
Jul 18 14:06:03 tlondon kernel: [<ffffffff81243741>] ? should_fail+0x97/0xf9
Jul 18 14:06:03 tlondon kernel: [<ffffffff8111b5ff>] kmem_cache_alloc+0xa7/0x159
Jul 18 14:06:03 tlondon kernel: [<ffffffff810e5933>] ? mempool_alloc_slab+0x15/0x17
Jul 18 14:06:03 tlondon kernel: [<ffffffff810e5933>] mempool_alloc_slab+0x15/0x17
Jul 18 14:06:03 tlondon kernel: [<ffffffff810e5acd>] mempool_alloc+0x71/0x11c
Jul 18 14:06:03 tlondon kernel: [<ffffffff8107e358>] ? lock_release+0x19a/0x1a6
Jul 18 14:06:03 tlondon kernel: [<ffffffff8121d188>] get_request+0x198/0x28b
Jul 18 14:06:03 tlondon kernel: [<ffffffff8121df16>] get_request_wait+0x37/0x196
Jul 18 14:06:03 tlondon kernel: [<ffffffff8122d04b>] ? cfq_merge+0x6c/0x95
Jul 18 14:06:03 tlondon kernel: [<ffffffff8121882d>] ? elv_merge+0x125/0x167
Jul 18 14:06:03 tlondon kernel: [<ffffffff8121e8c1>] __make_request+0x2e9/0x3f0
Jul 18 14:06:03 tlondon kernel: [<ffffffff8121bd11>] generic_make_request+0x285/0x301
Jul 18 14:06:03 tlondon kernel: [<ffffffff8121be67>] submit_bio+0xda/0xf7
Jul 18 14:06:03 tlondon kernel: [<ffffffff8114b407>] submit_bh+0xf4/0x11a
Jul 18 14:06:03 tlondon kernel: [<ffffffff8114d80b>] __block_write_full_page+0x1d3/0x2bd
Jul 18 14:06:03 tlondon kernel: [<ffffffff811502a7>] ? blkdev_get_block+0x0/0x6a
Jul 18 14:06:03 tlondon kernel: [<ffffffff8114e150>] ? end_buffer_async_write+0x0/0x173
Jul 18 14:06:03 tlondon kernel: [<ffffffff8114e150>] ? end_buffer_async_write+0x0/0x173
Jul 18 14:06:03 tlondon kernel: [<ffffffff811502a7>] ? blkdev_get_block+0x0/0x6a
Jul 18 14:06:03 tlondon kernel: [<ffffffff8114d97e>] block_write_full_page_endio+0x89/0x95
Jul 18 14:06:03 tlondon kernel: [<ffffffff8114d99f>] block_write_full_page+0x15/0x17
Jul 18 14:06:03 tlondon kernel: [<ffffffff81151144>] blkdev_writepage+0x18/0x1a
Jul 18 14:06:03 tlondon kernel: [<ffffffff810eaf65>] __writepage+0x1a/0x39
Jul 18 14:06:03 tlondon kernel: [<ffffffff810eb5a0>] write_cache_pages+0x200/0x335
Jul 18 14:06:03 tlondon kernel: [<ffffffff810eaf4b>] ? __writepage+0x0/0x39
Jul 18 14:06:03 tlondon kernel: [<ffffffff810eb6fc>] generic_writepages+0x27/0x29
Jul 18 14:06:03 tlondon kernel: [<ffffffff810ec19f>] do_writepages+0x24/0x2d
Jul 18 14:06:03 tlondon kernel: [<ffffffff81145aec>] writeback_single_inode+0xaa/0x1ec
Jul 18 14:06:03 tlondon kernel: [<ffffffff81145faf>] writeback_sb_inodes+0xb0/0x139
Jul 18 14:06:03 tlondon kernel: [<ffffffff81146740>] ? writeback_inodes_wb+0xec/0x161
Jul 18 14:06:03 tlondon kernel: [<ffffffff811467a3>] writeback_inodes_wb+0x14f/0x161
Jul 18 14:06:03 tlondon kernel: [<ffffffff81146994>] wb_writeback+0x1df/0x25c
Jul 18 14:06:03 tlondon kernel: [<ffffffff81146b3d>] wb_do_writeback+0x12c/0x143
Jul 18 14:06:03 tlondon kernel: [<ffffffff81146b97>] bdi_writeback_task+0x43/0x11c
Jul 18 14:06:03 tlondon kernel: [<ffffffff8106b29b>] ? bit_waitqueue+0x17/0xa9
Jul 18 14:06:03 tlondon kernel: [<ffffffff810f8ab7>] ? bdi_start_fn+0x0/0xda
Jul 18 14:06:03 tlondon kernel: [<ffffffff810f8b2d>] bdi_start_fn+0x76/0xda
Jul 18 14:06:03 tlondon kernel: [<ffffffff810f8ab7>] ? bdi_start_fn+0x0/0xda
Jul 18 14:06:03 tlondon kernel: [<ffffffff8106aebc>] kthread+0x9a/0xa2
Jul 18 14:06:03 tlondon kernel: [<ffffffff8100aae4>] kernel_thread_helper+0x4/0x10
Jul 18 14:06:03 tlondon kernel: [<ffffffff81498dd0>] ? restore_args+0x0/0x30
Jul 18 14:06:03 tlondon kernel: [<ffffffff8106ae22>] ? kthread+0x0/0xa2
Jul 18 14:06:03 tlondon kernel: [<ffffffff8100aae0>] ? kernel_thread_helper+0x0/0x10
Jul 18 14:06:03 tlondon kernel: FIX blkdev_requests: Restoring 0xffff880131d473a0-0xffff880131d473a0=0x6b
Jul 18 14:06:03 tlondon kernel:
Jul 18 14:06:03 tlondon kernel: FIX blkdev_requests: Marking all objects used
Jul 18 14:06:03 tlondon kernel: systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
Jul 18 14:06:03 tlondon kernel: systemd[1]: Received SIGCHLD


Version-Release number of selected component (if applicable):
kernel-2.6.35-0.47.rc5.git2.fc14.x86_64

How reproducible:
I've only seen one of these.....

Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Tom London 2010-07-19 19:03:31 UTC
Created attachment 432979 [details]
BUG spew from previous runs with "Poison overwritten"

Not sure its related, but checking earlier logs, there are 2 similar BUG reports:

BUG kmalloc-4096 (Not tainted): Poison overwritten

Attached here.

Comment 2 Jeff Moyer 2010-07-19 19:57:13 UTC
Hmm, have you checked your memory lately?

Comment 3 Tom London 2010-07-19 20:11:10 UTC
No, but I can run memtest86+.  [Haven't seen any other 'obvious' failures though.]

What would be considered a reasonable "run time" for this?

Comment 4 Tom London 2010-07-19 21:40:14 UTC
I completed one complete pass of memtest86+ with no errors.

I'll leave it running all night tonight and report back tomorrow morning.

Comment 5 Jeff Moyer 2010-07-19 22:11:07 UTC
*sigh*  I spoke too soon.  Looking at your poisoned memory messages, it's not single bit errors.  Feel free to stop that memtest run.  Unfortunately, if you have corruption in various slabs, it's more likely to be random memory corruption than use-after-free.

Comment 6 Chuck Ebbert 2010-07-21 04:06:58 UTC
How can we debug this? Build a kernel with CONFIG_DEBUG_PAGEALLOC and see if this hits on a freed page?

Comment 7 Jeff Moyer 2010-07-21 12:59:09 UTC
That would be a good start, yes.

Comment 8 Tom London 2010-07-21 14:27:22 UTC
I've only seen this on
kernel-2.6.35-0.41.rc5.git1.fc14.x86_64
kernel-2.6.35-0.47.rc5.git2.fc14.x86_64

but not yet on 
kernel-2.6.35-0.49.rc5.git2.fc14.x86_64

[been running this since Mon Jul 19 13:36]

I've been waiting to see if I got it with 0.49....

Comment 9 Chuck Ebbert 2010-07-21 15:36:07 UTC
(In reply to comment #8)
> I've only seen this on
> kernel-2.6.35-0.41.rc5.git1.fc14.x86_64
> kernel-2.6.35-0.47.rc5.git2.fc14.x86_64
> 
> but not yet on 
> kernel-2.6.35-0.49.rc5.git2.fc14.x86_64
> 

Do you have any lirc drivers loaded / in use?

Comment 10 Tom London 2010-07-21 15:50:09 UTC
Don't believe so:

[root@tlondon ~]# lsmod | grep lirc
[root@tlondon ~]#

Comment 11 Chuck Ebbert 2010-07-21 20:00:36 UTC
This is possibly another symptom of bug 615707, which was only present in 0.41 and 0.47 . If that happened to hit a mapped page instead of an unmapped one it would clear just a single bit, which is consistent with what we are seeing here.

Comment 12 Bug Zapper 2010-07-30 12:39:56 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 14 development cycle.
Changing version to '14'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 13 Chuck Ebbert 2010-08-03 23:15:55 UTC
Is this still happening? If not, close the bug.

Comment 14 Tom London 2010-08-03 23:22:14 UTC
I haven't seen this since 18 July, and kernel-2.6.35-0.47.rc5.git2.fc14.x86_64.

So, this appears fixed since kernel-2.6.35-0.49.rc5.git2.fc14.x86_64

Per request, closing.....