From patchwork Sat Jan 19 02:13:51 2013 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Sedat Dilek X-Patchwork-Id: 2005921 Return-Path: X-Original-To: patchwork-linux-acpi@patchwork.kernel.org Delivered-To: patchwork-process-083081@patchwork1.kernel.org Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by patchwork1.kernel.org (Postfix) with ESMTP id 465F43FED4 for ; Sat, 19 Jan 2013 02:13:57 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753253Ab3ASCNy (ORCPT ); Fri, 18 Jan 2013 21:13:54 -0500 Received: from mail-qa0-f47.google.com ([209.85.216.47]:32971 "EHLO mail-qa0-f47.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752570Ab3ASCNx (ORCPT ); Fri, 18 Jan 2013 21:13:53 -0500 Received: by mail-qa0-f47.google.com with SMTP id a19so5694443qad.13 for ; Fri, 18 Jan 2013 18:13:51 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:x-received:reply-to:in-reply-to:references:date :message-id:subject:from:to:cc:content-type; bh=iOuQ5dgYyERUjd8mIVDzyxi62Sd7t/vLyPyygxAzxTI=; b=aR5dRNVhDZvekh8G6+V2TfW9aHK4dEqIP5mUVAkvuCechTeuco4ktSqyj3AXAw1kpm zrN7gK3NCNLtu4+OhkrHTR9hUqYPQEabHpV6chhAMoNsudBeROKgHwBtTquVAFK2aFOR gfX50aP87ISmIx19KGTCJxl9xzGWns0EgPDYhly2kK/TD+GEM9QejhHcuGpE7i6fPFyD oquAXq0y25CaEUL1EJmBE1rrunVZLS6kJ8pOOZyeOTyP6hf1Vk9v1hcL5R+Mt1LYB9gE 4yyyN/9mmasJZerHznmcUitrUsllOPhT06R/JFdoSAcM2Gk/IG6haq2ualjGUKOIhV28 eWRA== MIME-Version: 1.0 X-Received: by 10.49.104.136 with SMTP id ge8mr13052414qeb.8.1358561631820; Fri, 18 Jan 2013 18:13:51 -0800 (PST) Received: by 10.49.87.39 with HTTP; Fri, 18 Jan 2013 18:13:51 -0800 (PST) Reply-To: sedat.dilek@gmail.com In-Reply-To: References: <2890633.q9n75klkI9@vostro.rjw.lan> <1922388.1PvyliEuQR@vostro.rjw.lan> Date: Sat, 19 Jan 2013 03:13:51 +0100 Message-ID: Subject: Re: linux-next: Tree for Jan 18 [ BROKEN suspend: jbd2|acpi|pm? ] From: Sedat Dilek To: "Rafael J. Wysocki" Cc: Stephen Rothwell , linux-next@vger.kernel.org, linux-kernel@vger.kernel.org, "Theodore Ts'o" , linux-fsdevel , Linux PM List , Linux ACPI , Greg Kroah-Hartman , Jiri Slaby , alan@lxorguk.ukuu.org.uk, linux-fbdev@vger.kernel.org Sender: linux-acpi-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-acpi@vger.kernel.org On Sat, Jan 19, 2013 at 2:55 AM, Sedat Dilek wrote: > On Sat, Jan 19, 2013 at 12:58 AM, Rafael J. Wysocki wrote: >> On Saturday, January 19, 2013 12:41:11 AM Sedat Dilek wrote: >>> On Sat, Jan 19, 2013 at 12:39 AM, Rafael J. Wysocki wrote: >>> > On Saturday, January 19, 2013 12:28:55 AM Sedat Dilek wrote: >>> >> On Sat, Jan 19, 2013 at 12:25 AM, Rafael J. Wysocki wrote: >>> >> > On Friday, January 18, 2013 11:56:53 PM Sedat Dilek wrote: >>> >> >> On Fri, Jan 18, 2013 at 11:35 PM, Sedat Dilek wrote: >>> >> >> > On Fri, Jan 18, 2013 at 11:20 PM, Rafael J. Wysocki wrote: >>> >> >> >> On Friday, January 18, 2013 11:11:07 PM Sedat Dilek wrote: >>> >> >> >>> On Fri, Jan 18, 2013 at 5:37 AM, Stephen Rothwell wrote: >>> >> >> >>> > Hi all, >>> >> >> >>> > >>> >> >> >>> > Changes since 20130117: >>> >> >> >>> > >>> >> >> >>> > Undropped tree: samung >>> >> >> >>> > >>> >> >> >>> > The powerpc tree still had a build failure. >>> >> >> >>> > >>> >> >> >>> > The driver-core tree gained a build failure for which I applied a merge >>> >> >> >>> > fix patch. >>> >> >> >>> > >>> >> >> >>> > The gpio-lw tree gained a build failure so I used the version from >>> >> >> >>> > next-20130117. >>> >> >> >>> > >>> >> >> >>> > The samsung tree lost the majority of its conflicts but gained more >>> >> >> >>> > against the arm-soc and slave-dma tree. >>> >> >> >>> > >>> >> >> >>> > ---------------------------------------------------------------------------- >>> >> >> >>> > >>> >> >> >>> >>> >> >> >>> From my dmesg diff-file: >>> >> >> >>> >>> >> >> >>> +[ 288.730849] PM: Syncing filesystems ... done. >>> >> >> >>> +[ 294.050498] Freezing user space processes ... (elapsed 0.04 seconds) done. >>> >> >> >>> +[ 294.097024] Freezing remaining freezable tasks ... >>> >> >> >>> +[ 314.098849] Freezing of tasks failed after 20.01 seconds (1 tasks >>> >> >> >>> refusing to freeze, wq_busy=0): >>> >> >> >>> +[ 314.098862] jbd2/loop0-8 D ffffffff8180d780 0 297 2 0x00000000 >>> >> >> >>> +[ 314.098865] ffff880117ec5b68 0000000000000046 ffff880117ec5b08 >>> >> >> >>> ffffffff81044c29 >>> >> >> >>> +[ 314.098868] ffff88011829dc80 ffff880117ec5fd8 ffff880117ec5fd8 >>> >> >> >>> ffff880117ec5fd8 >>> >> >> >>> +[ 314.098871] ffff880119b34560 ffff88011829dc80 ffff880117ec5b68 >>> >> >> >>> ffff88011fad4738 >>> >> >> >>> +[ 314.098873] Call Trace: >>> >> >> >>> +[ 314.098881] [] ? default_spin_lock_flags+0x9/0x10 >>> >> >> >>> +[ 314.098885] [] ? __wait_on_buffer+0x30/0x30 >>> >> >> >>> +[ 314.098888] [] schedule+0x29/0x70 >>> >> >> >>> +[ 314.098890] [] io_schedule+0x8f/0xd0 >>> >> >> >>> +[ 314.098892] [] sleep_on_buffer+0xe/0x20 >>> >> >> >>> +[ 314.098896] [] __wait_on_bit+0x5f/0x90 >>> >> >> >>> +[ 314.098898] [] ? submit_bh+0x121/0x1e0 >>> >> >> >>> +[ 314.098900] [] ? __wait_on_buffer+0x30/0x30 >>> >> >> >>> +[ 314.098903] [] out_of_line_wait_on_bit+0x7c/0x90 >>> >> >> >>> +[ 314.098906] [] ? autoremove_wake_function+0x40/0x40 >>> >> >> >>> +[ 314.098909] [] __wait_on_buffer+0x2e/0x30 >>> >> >> >>> +[ 314.098913] [] >>> >> >> >>> jbd2_journal_commit_transaction+0x1791/0x1960 >>> >> >> >>> +[ 314.098917] [] ? sched_clock_cpu+0xbd/0x110 >>> >> >> >>> +[ 314.098920] [] ? add_wait_queue+0x60/0x60 >>> >> >> >>> +[ 314.098923] [] ? try_to_del_timer_sync+0x4f/0x70 >>> >> >> >>> +[ 314.098925] [] kjournald2+0xb8/0x240 >>> >> >> >>> +[ 314.098927] [] ? add_wait_queue+0x60/0x60 >>> >> >> >>> +[ 314.098929] [] ? commit_timeout+0x10/0x10 >>> >> >> >>> +[ 314.098931] [] kthread+0xc0/0xd0 >>> >> >> >>> +[ 314.098933] [] ? flush_kthread_worker+0xb0/0xb0 >>> >> >> >>> +[ 314.098936] [] ret_from_fork+0x7c/0xb0 >>> >> >> >>> +[ 314.098938] [] ? flush_kthread_worker+0xb0/0xb0 >>> >> >> >>> +[ 314.098969] >>> >> >> >>> +[ 314.098970] Restarting kernel threads ... done. >>> >> >> >>> +[ 314.099052] Restarting tasks ... done. >>> >> >> >>> >>> >> >> >>> Please, have a lot at it. >>> >> >> >> >>> >> >> >> This is a freezer failure while freezing kernel threads, so I don't think it's >>> >> >> >> related to ACPI or PM directly. >>> >> >> >> >>> >> >> >> Does it happen on every suspend? >>> >> >> >> >>> >> >> > >>> >> >> > No, I only did one S/R. >>> >> >> > >>> >> >> > I have built a 2nd new kernel where I pulled-in latest pm.git#linux-next. >>> >> >> > With this kernel two S/Rs were fine - but that says not much. >>> >> >> > >>> >> >> >>> >> >> After several S/Rs on the "buggy" -1 kernel I know see in my syslogs: >>> >> >> >>> >> >> Jan 18 23:50:02 fambox kernel: [ 141.853828] Disabling non-boot CPUs ... >>> >> >> Jan 18 23:50:02 fambox kernel: [ 141.956943] smpboot: CPU 1 is now offline >>> >> >> Jan 18 23:50:02 fambox kernel: [ 141.957438] NOHZ: local_softirq_pending 02 >>> >> >> Jan 18 23:50:02 fambox kernel: [ 141.957454] NOHZ: local_softirq_pending 02 >>> >> >> Jan 18 23:50:02 fambox kernel: [ 142.060830] smpboot: CPU 2 is now offline >>> >> >> Jan 18 23:50:02 fambox kernel: [ 142.164639] smpboot: CPU 3 is now offline >>> >> > >>> >> > Are you worried about the "local_softirq_pending" messages? >>> >> > >>> >> >>> >> That's the only new messages I have seen after several S/Rs. >>> > >>> > They are kind of unusual. >>> > >>> > Anyway, they seem to be related to CPU hotplug (CPU offline), so you can try >>> > if you can trigger them through the sysfs CPU offline/online interface. >>> > >>> >>> Can you explain that a bit clearer or give some sample lines for testing? >> >> There is a sysfs file >> >> /sys/devices/system/cpu/cpuX/online >> >> (where X=0,1,2,3,...) for each CPU core in the system. The value read from it >> indicates whether or not the given core is online (1 means online). Writing 0 >> to it means that the given core should be put offline. Writing 1 means to put >> it back online. You can simply write first 0s and than 1s to those files >> for CPUs > 0 multiple times in a row and see if that triggers messages like the >> above. If it does, that may mean there's been a change in kernel/cpu.c, for >> example, that causes it to appear. The change may have been made somewhere in >> arch/x86 too, though. >> >>> >> If you have a testcase for me to reproduce it here, I would be happy. >>> > >>> > Do you mean the freezer-related issue? >>> > >>> >>> Any one as I am still stepping in the dark. >>> I checked my disc-space as I built a lot of software today and run >>> once out of space. >>> But 1.7GiB should be enough on / for testing. >>> I wanted to run the new LTP version I built the last days. >>> Let's see what I get... >> >> Stress-testing the freezer is rather easy and doesn't require disk space. >> All it takes is to echo "freezer" to /sys/power/pm_test and then do >> "echo mem > /sys/power/state && sleep 1" in a loop. This is described in >> Documentation/power/basic-pm-debugging.txt IIRC. >> > > [ CCing TTY and FBDEV folks ] > > [ TESTCASE ] > > kernel-config: CONFIG_PM_DEBUG=y > > root# echo "freezer" > /sys/power/pm_test > > root# echo mem > /sys/power/state && sleep 1 > > This produces several TTY call-traces... > > +[ 810.417180] ------------[ cut here ]------------ > +[ 810.417203] WARNING: at drivers/tty/tty_buffer.c:475 > flush_to_ldisc+0x12f/0x1f0() > +[ 810.417207] Hardware name: 530U3BI/530U4BI/530U4BH > +[ 810.417210] tty is NULL > +[ 791.200932] Freezing remaining freezable tasks ... > +[ 810.417213] Modules linked in: bnep rfcomm parport_pc ppdev > snd_hda_codec_hdmi snd_hda_codec_realtek coretemp kvm_intel kvm arc4 > iwldvm ghash_clmulni_intel aesni_intel snd_hda_intel mac80211 xts > uvcvideo snd_hda_codec aes_x86_64 lrw snd_hwdep gf128mul > videobuf2_vmalloc joydev ablk_helper snd_pcm i915 videobuf2_memops > cryptd videobuf2_core snd_page_alloc videodev snd_seq_midi > snd_seq_midi_event iwlwifi snd_rawmidi snd_seq i2c_algo_bit snd_timer > drm_kms_helper psmouse snd_seq_device drm btusb microcode cfg80211 snd > bluetooth serio_raw soundcore lpc_ich samsung_laptop wmi mei mac_hid > video lp parport hid_generic r8169 usbhid hid > +[ 810.417307] Pid: 37, comm: kworker/0:1 Not tainted > 3.8.0-rc4-next20130118-3-iniza-generic #1 > +[ 810.417310] Call Trace: > +[ 810.417325] [] warn_slowpath_common+0x7f/0xc0 > +[ 810.417332] [] warn_slowpath_fmt+0x46/0x50 > +[ 810.417340] [] flush_to_ldisc+0x12f/0x1f0 > +[ 810.417349] [] process_one_work+0x155/0x460 > +[ 810.417357] [] worker_thread+0x168/0x410 > +[ 810.417364] [] ? manage_workers+0x2c0/0x2c0 > +[ 810.417371] [] kthread+0xc0/0xd0 > +[ 810.417377] [] ? flush_kthread_worker+0xb0/0xb0 > +[ 810.417385] [] ret_from_fork+0x7c/0xb0 > +[ 810.417427] [] ? flush_kthread_worker+0xb0/0xb0 > +[ 810.417438] ---[ end trace a302c76f044b14c2 ]--- > > ...and my first reported call-trace is also seen afterwards... > > +[ 811.192835] Freezing of tasks failed after 20.01 seconds (1 tasks > refusing to freeze, wq_busy=0): > +[ 811.192957] jbd2/loop0-8 D ffffffff8180d780 0 289 2 0x00000000 > +[ 811.192966] ffff880118115b68 0000000000000046 ffff880118761720 > 0000000000000001 > +[ 811.192974] ffff880118761720 ffff880118115fd8 ffff880118115fd8 > ffff880118115fd8 > +[ 811.192981] ffffffff81c15440 ffff880118761720 ffff880118115b68 > ffff88011fa14738 > +[ 811.192988] Call Trace: > +[ 811.193006] [] ? __wait_on_buffer+0x30/0x30 > +[ 811.193015] [] schedule+0x29/0x70 > +[ 811.193021] [] io_schedule+0x8f/0xd0 > +[ 811.193028] [] sleep_on_buffer+0xe/0x20 > +[ 811.193037] [] __wait_on_bit+0x5f/0x90 > +[ 811.193044] [] ? submit_bh+0x121/0x1e0 > +[ 811.193051] [] ? __wait_on_buffer+0x30/0x30 > +[ 811.193058] [] out_of_line_wait_on_bit+0x7c/0x90 > +[ 811.193067] [] ? autoremove_wake_function+0x40/0x40 > +[ 811.193073] [] __wait_on_buffer+0x2e/0x30 > +[ 811.193085] [] > jbd2_journal_commit_transaction+0x1791/0x1960 > +[ 811.193093] [] ? _raw_spin_lock_irqsave+0x2e/0x40 > +[ 811.193102] [] ? try_to_del_timer_sync+0x4f/0x70 > +[ 811.193109] [] kjournald2+0xb8/0x240 > +[ 811.193115] [] ? add_wait_queue+0x60/0x60 > +[ 811.193120] [] ? commit_timeout+0x10/0x10 > +[ 811.193126] [] kthread+0xc0/0xd0 > +[ 811.193132] [] ? flush_kthread_worker+0xb0/0xb0 > +[ 811.193139] [] ret_from_fork+0x7c/0xb0 > +[ 811.193144] [] ? flush_kthread_worker+0xb0/0xb0 > +[ 811.193228] > +[ 811.193231] Restarting kernel threads ... done. > +[ 811.193403] Restarting tasks ... done. > > Thanks Rafael for the hints and your patience! > > Hope TTY/FBDEV folks can help. > > IMPORTANT NOTE: > I have tested with some patches on top of Linux-Next (next-20130118), > see attached patches file! > This looks like a typo to me... - Sedat - > - Sedat - > >> Thanks, >> Rafael >> >> >> -- >> I speak only for myself. >> Rafael J. Wysocki, Intel Open Source Technology Center. --- To unsubscribe from this list: send the line "unsubscribe linux-acpi" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html --- a/drivers/tty/tty_buffer.c +++ b/drivers/tty/tty_buffer.c @@ -471,7 +471,7 @@ static void flush_to_ldisc(struct work_struct *work) unsigned long flags; struct tty_ldisc *disc; - tty = port->itty; + tty = port->tty; if (WARN_RATELIMIT(tty == NULL, "tty is NULL\n")) return;