From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754716AbZCUVpN (ORCPT ); Sat, 21 Mar 2009 17:45:13 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1751399AbZCUVoz (ORCPT ); Sat, 21 Mar 2009 17:44:55 -0400 Received: from mu-out-0910.google.com ([209.85.134.189]:57418 "EHLO mu-out-0910.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751417AbZCUVow (ORCPT ); Sat, 21 Mar 2009 17:44:52 -0400 DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:user-agent:mime-version:to:cc:subject :content-type; b=NRP2yC8mSvRoQF8Gq7ZYe/l0aD2kj41xn8FPwl811qPQPTQggdsP8YjGnHctPF5J56 1vi9vFsHiPKE0oFee4OtwrL2Q3un5IOl0fYa//h757Xw4uhvCVz4WzhezeeGYtf5qwd1 Yi785wIZsLyO44P0vY8Ojp+z6Gsvdr376nweE= Message-ID: <49C5C251.50903@gmail.com> Date: Sun, 22 Mar 2009 05:45:05 +0100 From: jan sonnek User-Agent: Thunderbird 2.0.0.21 (X11/20090320) MIME-Version: 1.0 To: linux-kernel@vger.kernel.org CC: catalin.marinas@arm.com, linux-scsi@vger.kernel.org, akpm@linux-foundation.org Subject: Re: Regression - locking (all from 2.6.28) Content-Type: multipart/mixed; boundary="------------030008090006040105080009" Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org This is a multi-part message in MIME format. --------------030008090006040105080009 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit I have tried applied some patch (view down) to -mm kernel (last mmotm 26.29-rc8-mm1), but It was not successfull. When I have disabled Acceleration (Option "NoAccel" "true"), I was able to start X system, but in my dmesg is still error messages (attachement) Bug page: http://bugzilla.kernel.org/show_bug.cgi?id=12619 > On Mon, 2009-03-02 at 12:11 -0800, Andrew Morton wrote: > > > Mar 1 00:06:51 localhost kernel: [ 74.008165] unreferenced object 0xf6c4daf0 (size 52): > > > Mar 1 00:06:51 localhost kernel: [ 74.008170] comm "swapper", pid 1, jiffies 4294893427 > > > Mar 1 00:06:51 localhost kernel: [ 74.008175] backtrace: > > > Mar 1 00:06:51 localhost kernel: [ 74.008179] [] kmemleak_alloc+0x17e/0x28e > > > Mar 1 00:06:51 localhost kernel: [ 74.008185] [] kmem_cache_alloc+0xdc/0xe7 > > > Mar 1 00:06:51 localhost kernel: [ 74.008190] [] alloc_buffer_head+0x16/0x71 > > > Mar 1 00:06:51 localhost kernel: [ 74.008196] [] alloc_page_buffers+0x23/0xad > > > Mar 1 00:06:51 localhost kernel: [ 74.008200] [] __getblk+0x192/0x26b > > > Mar 1 00:06:51 localhost kernel: [ 74.008205] [] jread+0x105/0x1de > > > Mar 1 00:06:51 localhost kernel: [ 74.008209] [] do_one_pass+0x5e/0x38c > > > Mar 1 00:06:51 localhost kernel: [ 74.008213] [] journal_recover+0x41/0x9d > > > Mar 1 00:06:51 localhost kernel: [ 74.008218] [] journal_load+0x47/0x7b > > > Mar 1 00:06:51 localhost kernel: [ 74.008221] [] ext3_fill_super+0xe9d/0x144c > > > Mar 1 00:06:51 localhost kernel: [ 74.008225] [] get_sb_bdev+0xfa/0x140 > > > Mar 1 00:06:51 localhost kernel: [ 74.008231] [] ext3_get_sb+0x18/0x1a > > > Mar 1 00:06:51 localhost kernel: [ 74.008235] [] vfs_kern_mount+0x41/0x7c > > > Mar 1 00:06:51 localhost kernel: [ 74.008241] [] do_kern_mount+0x37/0xbe > > > Mar 1 00:06:51 localhost kernel: [ 74.008247] [] do_mount+0x5f7/0x630 > > > Mar 1 00:06:51 localhost kernel: [ 74.008253] [] sys_mount+0x6f/0xac > > I suspect kmemleak has gone nuts here. > > It seems that the buffer_head structure allocated above is stored in > page->private. However, the page structures are no longer scanned in > newer versions of kmemleak. That's the hunk that was removed after > comments about the contiguity of a node's memory: > > + /* mem_map scanning */ > + for_each_online_node(i) { > + struct page *page, *end; > + > + page = NODE_MEM_MAP(i); > + end = page + NODE_DATA(i)->node_spanned_pages; > + > + scan_block(page, end, NULL); > + } > > The alternative is to inform kmemleak about the page structures returned > from __alloc_pages_internal() but there would be problems with recursive > calls into kmemleak when it allocates its own data structures. > > I'll look at re-adding the hunk above, maybe with some extra checks like > pfn_valid(). Looking again at this, the node_mem_map is always contiguous and the code above only scans the node_mem_map, not the memory represented by the node (which may not be contiguous). So I think it is a valid code sequence. If the above gets too deep into the nodes structure, an alternative would be: diff --git a/mm/page_alloc.c b/mm/page_alloc.c index 09b6fd7..0f17e62 100644 --- a/mm/page_alloc.c +++ b/mm/page_alloc.c @@ -3552,6 +3552,11 @@ static void __init_refok alloc_node_mem_map(struct pglist_data *pgdat) map = alloc_remap(pgdat->node_id, size); if (!map) map = alloc_bootmem_node(pgdat, size); + /* + * Inform kmemleak to scan the node_mem_map arrays as the page + * structure may contain pointers to other objects. + */ + kmemleak_alloc(map, size, 1, GFP_ATOMIC); pgdat->node_mem_map = map + (pgdat->node_start_pfn - start); } #ifndef CONFIG_NEED_MULTIPLE_NODES -- Many thanks, Jan Sonnek --------------030008090006040105080009 Content-Type: text/plain; name="dmesg-noaccel" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="dmesg-noaccel" [ 1724.965479] ========================================================= [ 1724.965491] [ INFO: possible irq lock inversion dependency detected ] [ 1724.965501] 2.6.29-rc8-mm1-hanny #23 [ 1724.965507] --------------------------------------------------------- [ 1724.965516] swapper/0 just changed the state of lock: [ 1724.965523] (fasync_lock){.-....}, at: [] kill_fasync+0x20/0x3a [ 1724.965545] but this lock took another, HARDIRQ-unsafe lock in the past: [ 1724.965552] (&f->f_lock){+.+...} [ 1724.965560] [ 1724.965562] and interrupts could create inverse lock ordering between them. [ 1724.965568] [ 1724.965574] [ 1724.965576] other info that might help us debug this: [ 1724.965584] 3 locks held by swapper/0: [ 1724.965590] #0: (&dev->event_lock){-.-...}, at: [] input_event+0x35/0x6a [ 1724.965610] #1: (rcu_read_lock){.+.+..}, at: [] __rcu_read_lock+0x0/0x30 [ 1724.965631] #2: (rcu_read_lock){.+.+..}, at: [] evdev_event+0x0/0xe2 [ 1724.965649] [ 1724.965651] the first lock's dependencies: [ 1724.965657] -> (fasync_lock){.-....} ops: 253 { [ 1724.965672] IN-HARDIRQ-R at: [ 1724.965681] [] __lock_acquire+0x204/0xb4a [ 1724.965696] [] lock_acquire+0xb7/0xd4 [ 1724.965709] [] _read_lock+0x2d/0x5d [ 1724.965722] [] kill_fasync+0x20/0x3a [ 1724.965733] [] evdev_pass_event+0x60/0x66 [ 1724.965745] [] evdev_event+0x73/0xe2 [ 1724.965758] [] input_pass_event+0x5c/0x7f [ 1724.965771] [] input_handle_event+0x366/0x36f [ 1724.965784] [] input_event+0x54/0x6a [ 1724.965796] [] hidinput_hid_event+0x24c/0x279 [ 1724.965811] [] hid_process_event+0x8d/0xbc [ 1724.965824] [] hid_report_raw_event+0x33c/0x348 [ 1724.965838] [] hid_input_report+0xab/0xbc [ 1724.965851] [] hid_irq_in+0x86/0x182 [ 1724.965864] [] usb_hcd_giveback_urb+0x68/0x9c [ 1724.965878] [] uhci_giveback_urb+0xf6/0x1f1 [ 1724.965891] [] uhci_scan_schedule+0x5f8/0x85f [ 1724.965903] [] uhci_irq+0x12b/0x13f [ 1724.965916] [] usb_hcd_irq+0x32/0x81 [ 1724.965928] [] handle_IRQ_event+0xa4/0x121 [ 1724.965942] [] handle_fasteoi_irq+0x77/0xb0 [ 1724.965955] [] 0xffffffff [ 1724.965967] INITIAL USE at: [ 1724.965974] [] __lock_acquire+0x344/0xb4a [ 1724.965986] [] lock_acquire+0xb7/0xd4 [ 1724.965998] [] _write_lock_irq+0x33/0x63 [ 1724.966010] [] fasync_helper+0x44/0xe4 [ 1724.966022] [] tty_fasync+0x50/0xea [ 1724.966037] [] tty_release_dev+0x57/0x409 [ 1724.966049] [] tty_release+0x17/0x21 [ 1724.966062] [] __fput+0xcf/0x158 [ 1724.966074] [] fput+0x1e/0x20 [ 1724.966085] [] filp_close+0x56/0x60 [ 1724.966098] [] sys_close+0x6f/0xa9 [ 1724.966110] [] sysenter_do_call+0x12/0x35 [ 1724.966124] [] 0xffffffff [ 1724.966133] } [ 1724.966138] ... key at: [] fasync_lock+0x10/0x24 [ 1724.966152] -> (&f->f_lock){+.+...} ops: 427 { [ 1724.966166] HARDIRQ-ON-W at: [ 1724.966174] [] __lock_acquire+0x2c2/0xb4a [ 1724.966188] [] lock_acquire+0xb7/0xd4 [ 1724.966200] [] _spin_lock+0x2d/0x5d [ 1724.966213] [] do_fcntl+0x222/0x2bc [ 1724.966225] [] sys_fcntl64+0x5a/0x6e [ 1724.966238] [] sysenter_do_call+0x12/0x35 [ 1724.966250] [] 0xffffffff [ 1724.966261] SOFTIRQ-ON-W at: [ 1724.966269] [] __lock_acquire+0x2e5/0xb4a [ 1724.966281] [] lock_acquire+0xb7/0xd4 [ 1724.966293] [] _spin_lock+0x2d/0x5d [ 1724.966305] [] do_fcntl+0x222/0x2bc [ 1724.966318] [] sys_fcntl64+0x5a/0x6e [ 1724.966329] [] sysenter_do_call+0x12/0x35 [ 1724.966340] [] 0xffffffff [ 1724.966351] INITIAL USE at: [ 1724.966358] [] __lock_acquire+0x344/0xb4a [ 1724.966371] [] lock_acquire+0xb7/0xd4 [ 1724.966383] [] _spin_lock+0x2d/0x5d [ 1724.966395] [] fasync_helper+0xb4/0xe4 [ 1724.966407] [] tty_fasync+0x50/0xea [ 1724.966419] [] tty_release_dev+0x57/0x409 [ 1724.966431] [] tty_release+0x17/0x21 [ 1724.966444] [] __fput+0xcf/0x158 [ 1724.966455] [] fput+0x1e/0x20 [ 1724.966466] [] filp_close+0x56/0x60 [ 1724.966480] [] sys_close+0x6f/0xa9 [ 1724.966492] [] sysenter_do_call+0x12/0x35 [ 1724.966505] [] 0xffffffff [ 1724.966515] } [ 1724.966519] ... key at: [] __key.20487+0x0/0x8 [ 1724.966531] ... acquired at: [ 1724.966536] [] __lock_acquire+0x9c7/0xb4a [ 1724.966547] [] lock_acquire+0xb7/0xd4 [ 1724.966557] [] _spin_lock+0x2d/0x5d [ 1724.966566] [] fasync_helper+0xb4/0xe4 [ 1724.966575] [] tty_fasync+0x50/0xea [ 1724.966585] [] tty_release_dev+0x57/0x409 [ 1724.966595] [] tty_release+0x17/0x21 [ 1724.966605] [] __fput+0xcf/0x158 [ 1724.966614] [] fput+0x1e/0x20 [ 1724.966622] [] filp_close+0x56/0x60 [ 1724.966633] [] sys_close+0x6f/0xa9 [ 1724.966643] [] sysenter_do_call+0x12/0x35 [ 1724.966653] [] 0xffffffff [ 1724.966662] [ 1724.966666] [ 1724.966668] the second lock's dependencies: [ 1724.966675] -> (&f->f_lock){+.+...} ops: 427 { [ 1724.966689] HARDIRQ-ON-W at: [ 1724.966696] [] __lock_acquire+0x2c2/0xb4a [ 1724.966710] [] lock_acquire+0xb7/0xd4 [ 1724.966722] [] _spin_lock+0x2d/0x5d [ 1724.966734] [] do_fcntl+0x222/0x2bc [ 1724.966746] [] sys_fcntl64+0x5a/0x6e [ 1724.966758] [] sysenter_do_call+0x12/0x35 [ 1724.966770] [] 0xffffffff [ 1724.966781] SOFTIRQ-ON-W at: [ 1724.966788] [] __lock_acquire+0x2e5/0xb4a [ 1724.966801] [] lock_acquire+0xb7/0xd4 [ 1724.966814] [] _spin_lock+0x2d/0x5d [ 1724.966825] [] do_fcntl+0x222/0x2bc [ 1724.966836] [] sys_fcntl64+0x5a/0x6e [ 1724.966847] [] sysenter_do_call+0x12/0x35 [ 1724.966860] [] 0xffffffff [ 1724.966870] INITIAL USE at: [ 1724.966877] [] __lock_acquire+0x344/0xb4a [ 1724.966890] [] lock_acquire+0xb7/0xd4 [ 1724.966903] [] _spin_lock+0x2d/0x5d [ 1724.966914] [] fasync_helper+0xb4/0xe4 [ 1724.966926] [] tty_fasync+0x50/0xea [ 1724.966939] [] tty_release_dev+0x57/0x409 [ 1724.966951] [] tty_release+0x17/0x21 [ 1724.966963] [] __fput+0xcf/0x158 [ 1724.966975] [] fput+0x1e/0x20 [ 1724.966987] [] filp_close+0x56/0x60 [ 1724.966999] [] sys_close+0x6f/0xa9 [ 1724.967011] [] sysenter_do_call+0x12/0x35 [ 1724.967024] [] 0xffffffff [ 1724.967034] } [ 1724.967038] ... key at: [] __key.20487+0x0/0x8 [ 1724.967049] [ 1724.967051] stack backtrace: [ 1724.967059] Pid: 0, comm: swapper Not tainted 2.6.29-rc8-mm1-hanny #23 [ 1724.967066] Call Trace: [ 1724.967077] [] ? printk+0x14/0x17 [ 1724.967087] [] print_irq_inversion_bug+0xea/0xf7 [ 1724.967098] [] check_usage_forwards+0x36/0x3f [ 1724.967107] [] mark_lock+0x110/0x1f4 [ 1724.967117] [] ? check_usage_forwards+0x0/0x3f [ 1724.967128] [] __lock_acquire+0x204/0xb4a [ 1724.967140] [] lock_acquire+0xb7/0xd4 [ 1724.967150] [] ? kill_fasync+0x20/0x3a [ 1724.967160] [] _read_lock+0x2d/0x5d [ 1724.967170] [] ? kill_fasync+0x20/0x3a [ 1724.967179] [] kill_fasync+0x20/0x3a [ 1724.967189] [] evdev_pass_event+0x60/0x66 [ 1724.967198] [] evdev_event+0x73/0xe2 [ 1724.967210] [] input_pass_event+0x5c/0x7f [ 1724.967220] [] input_handle_event+0x366/0x36f [ 1724.967232] [] ? add_timer_randomness+0xee/0x108 [ 1724.967243] [] input_event+0x54/0x6a [ 1724.967254] [] hidinput_hid_event+0x24c/0x279 [ 1724.967265] [] hid_process_event+0x8d/0xbc [ 1724.967276] [] hid_report_raw_event+0x33c/0x348 [ 1724.967289] [] hid_input_report+0xab/0xbc [ 1724.967299] [] hid_irq_in+0x86/0x182 [ 1724.967309] [] ? usb_unanchor_urb+0xb/0x85 [ 1724.967320] [] usb_hcd_giveback_urb+0x68/0x9c [ 1724.967331] [] uhci_giveback_urb+0xf6/0x1f1 [ 1724.967340] [] ? _spin_unlock_irqrestore+0x58/0x65 [ 1724.967352] [] uhci_scan_schedule+0x5f8/0x85f [ 1724.967363] [] ? put_lock_stats+0x1e/0x29 [ 1724.967374] [] uhci_irq+0x12b/0x13f [ 1724.967384] [] usb_hcd_irq+0x32/0x81 [ 1724.967395] [] handle_IRQ_event+0xa4/0x121 [ 1724.967406] [] handle_fasteoi_irq+0x77/0xb0 [ 1724.967416] [] ? handle_fasteoi_irq+0x0/0xb0 [ 1724.967423] [] ? do_IRQ+0x4a/0x8c [ 1724.967440] [] ? common_interrupt+0x2e/0x34 [ 1724.967452] [] ? timekeeping_suspend+0x61/0x70 [ 1724.967465] [] ? acpi_idle_enter_simple+0x13a/0x165 [ 1724.967477] [] ? cpuidle_idle_call+0x6a/0x9c [ 1724.967487] [] ? cpu_idle+0x7f/0xb4 [ 1724.967498] [] ? start_secondary+0x20e/0x24e [ 1921.835352] unreferenced object 0xf2fa1100 (size 64): [ 1921.835359] comm "dbus-daemon", pid 2852, jiffies 364589 [ 1921.835363] backtrace: [ 1921.835372] [] kmemleak_alloc+0x17e/0x291 [ 1921.835377] [] __kmalloc+0x10f/0x11a [ 1921.835382] [] do_sys_poll+0xb8/0x3bf [ 1921.835386] [] sys_poll+0x45/0x8f [ 1921.835391] [] sysenter_do_call+0x12/0x35 [ 1921.835396] [] 0xffffffff --------------030008090006040105080009--