Return-Path: linux-nfs-owner@vger.kernel.org Received: from mail-vw0-f46.google.com ([209.85.212.46]:34076 "EHLO mail-vw0-f46.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751348Ab1K0H4B convert rfc822-to-8bit (ORCPT ); Sun, 27 Nov 2011 02:56:01 -0500 MIME-Version: 1.0 In-Reply-To: <20111123124656.35063401@corrin.poochiereds.net> References: <4ECCAF76.3090502@linux.vnet.ibm.com> <20111123124656.35063401@corrin.poochiereds.net> Date: Sun, 27 Nov 2011 08:55:59 +0100 Message-ID: Subject: Re: Freezing of tasks failed after 20.01 seconds in kernel 3.2.0-rc2 From: Belisko Marek To: Jeff Layton Cc: "Srivatsa S. Bhat" , LKML , "Rafael J. Wysocki" , linux-nfs@vger.kernel.org, Linux PM mailing list , john@calva.com, Tejun Heo , trond.myklebust@netapp.com Content-Type: text/plain; charset=UTF-8 Sender: linux-nfs-owner@vger.kernel.org List-ID: On Wed, Nov 23, 2011 at 6:46 PM, Jeff Layton wrote: > On Wed, 23 Nov 2011 14:01:50 +0530 > "Srivatsa S. Bhat" wrote: > >> On 11/23/2011 02:50 AM, Belisko Marek wrote: >> > Using 3.2.0-rc2 on my laptop once I've seen following trace when suspend: >> > >> > [15215.853880] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready >> > [15221.646580] psmouse serio2: bad data from KBC - timeout >> > [15221.857213] psmouse serio2: bad data from KBC - timeout >> > [15226.960037] wlan0: no IPv6 routers present >> > [15278.513091] wlan0: deauthenticating from 00:1e:58:14:6c:44 by local >> > choice (reason=3) >> > [15278.537857] cfg80211: All devices are disconnected, going to >> > restore regulatory settings >> > [15278.537865] cfg80211: Restoring regulatory settings >> > [15278.537872] cfg80211: Calling CRDA to update world regulatory domain >> > [15278.546284] cfg80211: Ignoring regulatory request Set by core since >> > the driver uses its own custom regulatory domain >> > [15278.546290] cfg80211: World regulatory domain updated: >> > [15278.546294] cfg80211: (start_freq - end_freq @ bandwidth), >> > (max_antenna_gain, max_eirp) >> > [15278.546300] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), >> > (300 mBi, 2000 mBm) >> > [15278.546305] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), >> > (300 mBi, 2000 mBm) >> > [15278.546310] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), >> > (300 mBi, 2000 mBm) >> > [15278.546315] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), >> > (300 mBi, 2000 mBm) >> > [15278.546321] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), >> > (300 mBi, 2000 mBm) >> > [15280.417945] init: anacron main process (10148) killed by TERM signal >> > [15281.558943] PM: Syncing filesystems ... done. >> > [15281.970184] PM: Preparing system for mem sleep >> > [15282.284192] Freezing user space processes ... >> > [15302.300305] Freezing of tasks failed after 20.01 seconds (1 tasks >> > refusing to freeze, wq_busy=0): >> > [15302.300485] mount.nfs D f1bb7a1c 0 9987 9985 0x00800004 >> > [15302.300494] f1bb7a74 00000082 c1539243 f1bb7a1c f9220b89 f1bb79f8 >> > c1026778 c1878340 >> > [15302.300507] f046cc20 c1878340 c1878340 1e6f8d83 00000de6 c1878340 >> > f4a07340 f046cc20 >> > [15302.300518] f1a658d0 f3898000 f1bb7a48 c1055e95 00000000 f3898000 >> > 0039d700 00000286 >> > [15302.300530] Call Trace: >> > [15302.300542] [] ? _raw_read_unlock_bh+0x13/0x20 >> > [15302.300566] [] ? xs_tcp_state_change+0x49/0x280 [sunrpc] >> > [15302.300574] [] ? default_spin_lock_flags+0x8/0x10 >> > [15302.300582] [] ? mod_timer+0x135/0x260 >> > [15302.300601] [] ? __rpc_sleep_on_priority+0x173/0x240 [sunrpc] >> > [15302.300607] [] ? default_spin_lock_flags+0x8/0x10 >> > [15302.300613] [] ? _raw_spin_lock_irqsave+0x2f/0x50 >> > [15302.300619] [] schedule+0x35/0x50 >> > [15302.300637] [] rpc_wait_bit_killable+0x1e/0x40 [sunrpc] >> > [15302.300643] [] __wait_on_bit+0x4d/0x70 >> > [15302.300661] [] ? rpc_queue_empty+0x40/0x40 [sunrpc] >> > [15302.300679] [] ? rpc_queue_empty+0x40/0x40 [sunrpc] >> > [15302.300685] [] out_of_line_wait_on_bit+0xab/0xc0 >> > [15302.300692] [] ? autoremove_wake_function+0x50/0x50 >> > [15302.300710] [] __rpc_execute+0x167/0x270 [sunrpc] >> > [15302.300716] [] ? wake_up_bit+0x5e/0x70 >> > [15302.300734] [] rpc_execute+0x38/0x40 [sunrpc] >> > [15302.300749] [] rpc_run_task+0x59/0x70 [sunrpc] >> > [15302.300765] [] rpc_call_sync+0x3e/0x60 [sunrpc] >> > [15302.300782] [] rpc_ping+0x48/0x60 [sunrpc] >> > [15302.300799] [] rpc_create+0x397/0x4d0 [sunrpc] >> > [15302.300807] [] ? kmap_atomic_prot+0xdd/0x100 >> > [15302.300815] [] ? __nla_reserve+0x40/0x50 >> > [15302.300831] [] nfs_create_rpc_client+0xab/0xe0 [nfs] >> > [15302.300841] [] ? __fscache_acquire_cookie+0x59/0x270 [fscache] >> > [15302.300858] [] nfs4_init_client+0x62/0x170 [nfs] >> > [15302.300873] [] nfs_get_client+0x353/0x4e0 [nfs] >> > [15302.300880] [] ? mutex_lock+0x19/0x40 >> > [15302.300886] [] ? __percpu_counter_init+0x62/0x70 >> > [15302.300901] [] nfs4_set_client+0x5a/0xc0 [nfs] >> > [15302.300917] [] nfs4_create_server+0xc6/0x310 [nfs] >> > [15302.300936] [] nfs4_remote_mount+0x5e/0x2f0 [nfs] >> > [15302.300943] [] ? ida_get_new_above+0x101/0x1b0 >> > [15302.300951] [] mount_fs+0x36/0x170 >> > [15302.300960] [] ? __alloc_percpu+0xf/0x20 >> > [15302.300967] [] ? alloc_vfsmnt+0xae/0x130 >> > [15302.300974] [] vfs_kern_mount+0x4b/0xa0 >> > [15302.300991] [] nfs_do_root_mount+0x69/0x90 [nfs] >> > [15302.301008] [] ? nfs_parse_devname+0x8c/0x1a0 [nfs] >> > [15302.301026] [] nfs4_try_mount+0x3f/0xb0 [nfs] >> > [15302.301043] [] ? nfs4_validate_text_mount_data+0x85/0x100 [nfs] >> > [15302.301060] [] nfs_fs_mount+0x465/0xb20 [nfs] >> > [15302.301066] [] ? pcpu_alloc_area+0x210/0x320 >> > [15302.301073] [] ? pcpu_next_pop+0x38/0x50 >> > [15302.301078] [] ? pcpu_alloc+0x354/0x830 >> > [15302.301085] [] ? ida_get_new_above+0x101/0x1b0 >> > [15302.301092] [] ? __kmalloc_track_caller+0xf5/0x1a0 >> > [15302.301097] [] ? ida_get_new_above+0x101/0x1b0 >> > [15302.301104] [] mount_fs+0x36/0x170 >> > [15302.301110] [] ? __alloc_percpu+0xf/0x20 >> > [15302.301116] [] ? alloc_vfsmnt+0xae/0x130 >> > [15302.301123] [] vfs_kern_mount+0x4b/0xa0 >> > [15302.301129] [] do_kern_mount+0x3e/0xd0 >> > [15302.301135] [] do_mount+0x308/0x6d0 >> > [15302.301142] [] ? copy_mount_options+0xa8/0x120 >> > [15302.301148] [] sys_mount+0x6b/0xa0 >> > [15302.301154] [] syscall_call+0x7/0xb >> > [15302.301162] >> > [15302.301165] Restarting tasks ... done. >> > [15302.359593] video LNXVIDEO:00: Restoring backlight state >> > [15303.897565] init: anacron main process (10434) killed by TERM signal >> > [15304.088853] iwlwifi 0000:07:00.0: L1 Disabled; Enabling L0S >> > [15304.091810] iwlwifi 0000:07:00.0: Radio type=0x1-0x2-0x0 >> > [15304.139846] ADDRCONF(NETDEV_UP): wlan0: link is not ready >> > [15304.153864] atl1c 0000:09:00.0: irq 46 for MSI/MSI-X >> > [15304.212718] ADDRCONF(NETDEV_UP): eth0: link is not ready >> > >> > >> > Marek >> > >> >> Hi Marek, >> >> Thanks for the bug report. But this is a known issue and Jeff Layton >> is working on a patchset that aims to fix it. >> >> http://www.spinics.net/lists/linux-nfs/msg25585.html >> >> Can you please try it out and see if it fixes the issue for you? Hi I've applied both patches on top v3.2-rc3 and problem is gone. I make several suspend/resume and never seen reported behaviour. You can add my: Tested-by: Marek Belisko >> >> [I am wondering why Jeff did not CC LKML while sending the patchset!] >> >> Adding relevant people and linux-pm mailing list to CC. >> >> Thanks, >> Srivatsa S. Bhat >> > > Sorry, it was an oversight -- I should have cc'ed LKML. At this point, > the patchset seems to work as expected, but I need to respin it to > flesh out the comments. Testing it would be helpful. > > I'll be sure to cc LKML when I send the respun set... > > Thanks, > -- > Jeff Layton > regards, marek -- as simple and primitive as possible ------------------------------------------------- Marek Belisko - OPEN-NANDRA Freelance Developer Ruska Nova Ves 219 | Presov, 08005 Slovak Republic Tel: +421 915 052 184 skype: marekwhite twitter: #opennandra web: http://open-nandra.com