On Tue, Aug 21, 2012 at 8:33 PM, Daniel Vetter <daniel@xxxxxxxx> wrote: > On Tue, Aug 21, 2012 at 08:20:35PM +0200, Sedat Dilek wrote: >> On Tue, Aug 21, 2012 at 6:39 PM, Daniel Vetter <daniel@xxxxxxxx> wrote: >> > On Tue, Aug 21, 2012 at 3:24 PM, Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote: >> >> On Tue, Aug 21, 2012 at 1:53 PM, Daniel Vetter <daniel@xxxxxxxx> wrote: >> >>> On Tue, Aug 21, 2012 at 1:14 PM, Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote: >> >>>> On Tue, Aug 21, 2012 at 1:03 PM, Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote: >> >>>>> On Tue, Aug 21, 2012 at 1:02 PM, Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote: >> >>>>>> On Tue, Aug 21, 2012 at 8:04 AM, Stephen Rothwell <sfr@xxxxxxxxxxxxxxxx> wrote: >> >>>>>>> Hi all, >> >>>>>>> >> >>>>>>> Changes since 20120820: >> >>>>>>> >> >>>>>>> The rr tree gained a conflict against Linus' tree. >> >>>>>>> >> >>>>>>> The tip tree still has its build failure so I used the version from >> >>>>>>> next-20120814. >> >>>>>>> >> >>>>>>> The workqueues tree gained a conflict against the hid tree. >> >>>>>>> >> >>>>>>> The drivers-x86 tree still has its build failure so I used the version >> >>>>>>> from next-20120817. >> >>>>>>> >> >>>>>>> The signal tree gained a conflict against Linus' tree. I have still >> >>>>>>> reverted 3 commits from the signal tree at the request of the arm >> >>>>>>> maintainer. >> >>>>>>> >> >>>>>>> ---------------------------------------------------------------------------- >> >>>>>>> >> >>>>>> >> >>>>>> Hi, >> >>>>>> >> >>>>>> I have compiled linux-next (next-20120821) and see the attached >> >>>>>> call-trace when suspending. >> >>>>>> Suspending did NOT work (Xorg seems to cause it) - machine came back to desktop. >> >>>>>> >> >>>>>> With yesterday's next-20120820 I haven't seen this. >> >>>>>> >> >>>>>> I am not sure what is this causing... PM, x86/sched or even VFS? >> >>>>>> Any help for debugging appreciated. >> >>>>>> >> >>>>>> I am on Ubuntu/precise AMD64 and use systemd-v43 as init-system. >> >>>>>> >> >>>>>> Regards, >> >>>>>> - Sedat - >> >>>>> >> >>>>> Forgot attachment! >> >>>>> If you don't succeed - try try try... >> >>>>> >> >>>>> - Sedat - >> >>>> >> >>>> [ CC danvet ] >> >>>> >> >>>> I have pulled in drm-intel-fixes into my local GIT tree and rebuilt >> >>>> i915 - this seems to fix the problem. >> >>>> Daniel any suggestion which patch in d-i-f did it? >> >>> >> >>> Without the backtrace it's kinda hard to tell ... Also, if you can >> >>> dump a git log of the commits from -fixes that you don't yet have. >> >>> -Daniel >> >>> >> >> >> >> Hi Daniel, >> >> >> >> $ git log --oneline v3.6.0-rc2-next20120821-1-iniza-generic..drm-intel-fixes >> >> 1ee9ae3 drm/i915: use hsw rps tuning values everywhere on gen6+ >> >> f1a2f5b drm/i915: fall back to bit-banging if GMBUS fails in CRT EDID reads >> >> 4eab813 drm/i915: extract connector update from intel_ddc_get_modes() for reuse >> >> a843af1 drm/i915: fix hsw uncached pte >> >> b6c7488 drm/i915/contexts: fix list corruption >> >> 38ab8a2 drm/i915: fix EDID memory leak in SDVO >> >> >> >> Looks like "1ee9ae3 drm/i915: use hsw rps tuning values everywhere on >> >> gen6+" has PM fixes for i915. >> >> >> >> I tried with only that patch on top of today's linux-next - and I can >> >> suspend/resume again! >> > >> > Well, this is slightly shocking - this patch /should/ only optimize >> > power consumption, it should in now way fix suspend/resume (i.e. it >> > doesn't even apply any h/w workaround). Do you have any more details >> > what's going wrong here (logs, ...)? >> > >> >> Forgot to CC you on my 1st emails. >> [2] has the call-trace I have seen. >> >> - Sedat - >> >> [2] http://marc.info/?l=linux-next&m=134554704504603&w=2 > > Hm, that smells more like a race, and changing the gpu turbo settins is > known to rather massively move such races around (since this affects the > power consumption and hence also max cpu turbo states, besides massively > changing wakeup latency, since only when the gpu is in rc6 the entire > cpu+gpu package can go into the lowest power state). > > I'd wager this thing will pop up again :( I have re-installed the problematic kernel. After 3 suspends I could twice resume successfully. I have attached both kern-logs (1st reported call-trace, 2nd new one). First was caused by Xorg and the 2nd by aptd. $ sudo grep -A1 "Freezing of tasks failed after" /var/log/kern.log Aug 21 12:53:18 fambox kernel: [ 2569.853137] Freezing of tasks failed after 20.00 seconds (1 tasks refusing to freeze, wq_busy=0): Aug 21 12:53:18 fambox kernel: [ 2569.853151] Xorg D 0000000000000000 0 762 724 0x00400004 -- Aug 21 20:37:46 fambox kernel: [ 125.031876] Freezing of tasks failed after 20.01 seconds (1 tasks refusing to freeze, wq_busy=0): Aug 21 20:37:46 fambox kernel: [ 125.031909] aptd D ffffffff8180cd00 0 2071 1 0x00000004 IIRC PM is now async? - Sedat - > -Daniel > -- > Daniel Vetter > Mail: daniel@xxxxxxxx > Mobile: +41 (0)79 365 57 48
Aug 21 12:52:55 fambox kernel: [ 2547.097565] wlan0: deauthenticating from 00:04:0e:e4:00:3d by local choice (reason=3) Aug 21 12:52:55 fambox kernel: [ 2547.107563] cfg80211: All devices are disconnected, going to restore regulatory settings Aug 21 12:52:55 fambox kernel: [ 2547.107567] cfg80211: Restoring regulatory settings Aug 21 12:52:55 fambox kernel: [ 2547.107572] cfg80211: Calling CRDA to update world regulatory domain Aug 21 12:52:55 fambox kernel: [ 2547.111808] cfg80211: Ignoring regulatory request Set by core since the driver uses its own custom regulatory domain Aug 21 12:52:55 fambox kernel: [ 2547.111811] cfg80211: World regulatory domain updated: Aug 21 12:52:55 fambox kernel: [ 2547.111813] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) Aug 21 12:52:55 fambox kernel: [ 2547.111814] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Aug 21 12:52:55 fambox kernel: [ 2547.111816] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Aug 21 12:52:55 fambox kernel: [ 2547.111817] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Aug 21 12:52:55 fambox kernel: [ 2547.111819] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Aug 21 12:52:55 fambox kernel: [ 2547.111820] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Aug 21 12:52:57 fambox kernel: [ 2549.512159] PM: Syncing filesystems ... done. Aug 21 12:52:57 fambox kernel: [ 2549.514955] PM: Preparing system for mem sleep Aug 21 12:53:18 fambox kernel: [ 2549.866630] Freezing user space processes ... Aug 21 12:53:18 fambox kernel: [ 2569.853137] Freezing of tasks failed after 20.00 seconds (1 tasks refusing to freeze, wq_busy=0): Aug 21 12:53:18 fambox kernel: [ 2569.853151] Xorg D 0000000000000000 0 762 724 0x00400004 Aug 21 12:53:18 fambox kernel: [ 2569.853155] ffff88010046fad8 0000000000000082 00000000000213da ffffea00031bd680 Aug 21 12:53:18 fambox kernel: [ 2569.853158] ffff880116abc470 ffff88010046ffd8 ffff88010046ffd8 ffff88010046ffd8 Aug 21 12:53:18 fambox kernel: [ 2569.853160] ffff8801164616d0 ffff880116abc470 ffff88010046fad8 ffff88011fa546e0 Aug 21 12:53:18 fambox kernel: [ 2569.853163] Call Trace: Aug 21 12:53:18 fambox kernel: [ 2569.853170] [<ffffffff81128650>] ? sleep_on_page+0x20/0x20 Aug 21 12:53:18 fambox kernel: [ 2569.853173] [<ffffffff81631969>] schedule+0x29/0x70 Aug 21 12:53:18 fambox kernel: [ 2569.853175] [<ffffffff81631a3f>] io_schedule+0x8f/0xd0 Aug 21 12:53:18 fambox kernel: [ 2569.853178] [<ffffffff8112865e>] sleep_on_page_killable+0xe/0x40 Aug 21 12:53:18 fambox kernel: [ 2569.853180] [<ffffffff8163023f>] __wait_on_bit+0x5f/0x90 Aug 21 12:53:18 fambox kernel: [ 2569.853183] [<ffffffff8112ae30>] wait_on_page_bit_killable+0x80/0x90 Aug 21 12:53:18 fambox kernel: [ 2569.853188] [<ffffffff8107b870>] ? autoremove_wake_function+0x40/0x40 Aug 21 12:53:18 fambox kernel: [ 2569.853190] [<ffffffff8112aee6>] __lock_page_or_retry+0xa6/0xd0 Aug 21 12:53:18 fambox kernel: [ 2569.853193] [<ffffffff8112b2b7>] filemap_fault+0x3a7/0x480 Aug 21 12:53:18 fambox kernel: [ 2569.853197] [<ffffffff8114cf3f>] __do_fault+0x6f/0x500 Aug 21 12:53:18 fambox kernel: [ 2569.853200] [<ffffffff81194d30>] ? __pollwait+0xf0/0xf0 Aug 21 12:53:18 fambox kernel: [ 2569.853203] [<ffffffff81150007>] handle_pte_fault+0xf7/0x9a0 Aug 21 12:53:18 fambox kernel: [ 2569.853220] [<ffffffffa031e045>] ? i915_gem_set_domain_ioctl+0xc5/0x100 [i915] Aug 21 12:53:18 fambox kernel: [ 2569.853231] [<ffffffffa022f38c>] ? drm_ioctl+0x47c/0x540 [drm] Aug 21 12:53:18 fambox kernel: [ 2569.853234] [<ffffffff81151b09>] handle_mm_fault+0x259/0x340 Aug 21 12:53:18 fambox kernel: [ 2569.853238] [<ffffffff81636682>] __do_page_fault+0x152/0x520 Aug 21 12:53:18 fambox kernel: [ 2569.853240] [<ffffffff81193df8>] ? do_vfs_ioctl+0x98/0x550 Aug 21 12:53:18 fambox kernel: [ 2569.853243] [<ffffffff81636a5e>] do_page_fault+0xe/0x10 Aug 21 12:53:18 fambox kernel: [ 2569.853245] [<ffffffff816330e5>] page_fault+0x25/0x30 Aug 21 12:53:18 fambox kernel: [ 2569.853263] Aug 21 12:53:18 fambox kernel: [ 2569.853264] Restarting tasks ... done. Aug 21 12:53:18 fambox kernel: [ 2569.859587] video LNXVIDEO:00: Restoring backlight state Aug 21 12:53:19 fambox kernel: [ 2570.626230] iwlwifi 0000:01:00.0: L1 Enabled; Disabling L0S Aug 21 12:53:19 fambox kernel: [ 2570.632965] iwlwifi 0000:01:00.0: Radio type=0x1-0x2-0x0 Aug 21 12:53:19 fambox kernel: [ 2570.749438] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready Aug 21 12:53:19 fambox kernel: [ 2570.996426] cfg80211: Found new beacon on frequency: 2467 MHz (Ch 12) on phy0 Aug 21 12:53:25 fambox kernel: [ 2577.067220] wlan0: authenticate with 00:04:0e:e4:00:3d Aug 21 12:53:25 fambox kernel: [ 2577.076717] wlan0: send auth to 00:04:0e:e4:00:3d (try 1/3) Aug 21 12:53:25 fambox kernel: [ 2577.078612] wlan0: authenticated Aug 21 12:53:25 fambox kernel: [ 2577.079139] iwlwifi 0000:01:00.0: wlan0: disabling HT as WMM/QoS is not supported by the AP Aug 21 12:53:25 fambox kernel: [ 2577.079147] iwlwifi 0000:01:00.0: wlan0: disabling VHT as WMM/QoS is not supported by the AP Aug 21 12:53:25 fambox kernel: [ 2577.079891] wlan0: associate with 00:04:0e:e4:00:3d (try 1/3) Aug 21 12:53:25 fambox kernel: [ 2577.083887] wlan0: RX AssocResp from 00:04:0e:e4:00:3d (capab=0x411 status=0 aid=2) Aug 21 12:53:25 fambox kernel: [ 2577.090796] wlan0: associated Aug 21 12:53:25 fambox kernel: [ 2577.090886] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Aug 21 20:37:24 fambox kernel: [ 102.242530] wlan0: deauthenticating from 00:04:0e:e4:00:3d by local choice (reason=3) Aug 21 20:37:24 fambox kernel: [ 102.254177] cfg80211: All devices are disconnected, going to restore regulatory settings Aug 21 20:37:24 fambox kernel: [ 102.254186] cfg80211: Restoring regulatory settings Aug 21 20:37:24 fambox kernel: [ 102.254196] cfg80211: Calling CRDA to update world regulatory domain Aug 21 20:37:24 fambox kernel: [ 102.264169] cfg80211: Ignoring regulatory request Set by core since the driver uses its own custom regulatory domain Aug 21 20:37:24 fambox kernel: [ 102.264180] cfg80211: World regulatory domain updated: Aug 21 20:37:24 fambox kernel: [ 102.264185] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) Aug 21 20:37:24 fambox kernel: [ 102.264192] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Aug 21 20:37:24 fambox kernel: [ 102.264197] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Aug 21 20:37:24 fambox kernel: [ 102.264203] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Aug 21 20:37:24 fambox kernel: [ 102.264208] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Aug 21 20:37:24 fambox kernel: [ 102.264213] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Aug 21 20:37:26 fambox kernel: [ 104.696653] PM: Syncing filesystems ... done. Aug 21 20:37:26 fambox kernel: [ 104.702356] PM: Preparing system for mem sleep Aug 21 20:37:46 fambox kernel: [ 105.032995] Freezing user space processes ... Aug 21 20:37:46 fambox kernel: [ 125.031876] Freezing of tasks failed after 20.01 seconds (1 tasks refusing to freeze, wq_busy=0): Aug 21 20:37:46 fambox kernel: [ 125.031909] aptd D ffffffff8180cd00 0 2071 1 0x00000004 Aug 21 20:37:46 fambox kernel: [ 125.031912] ffff88004a061598 0000000000000086 0000000000000082 ffff88004a061548 Aug 21 20:37:46 fambox kernel: [ 125.031915] ffff880056a45b40 ffff88004a061fd8 ffff88004a061fd8 ffff88004a061fd8 Aug 21 20:37:46 fambox kernel: [ 125.031918] ffff88011abb4470 ffff880056a45b40 ffff88004a061568 ffff88011fad46e0 Aug 21 20:37:46 fambox kernel: [ 125.031921] Call Trace: Aug 21 20:37:46 fambox kernel: [ 125.031928] [<ffffffff811b25d0>] ? __wait_on_buffer+0x30/0x30 Aug 21 20:37:46 fambox kernel: [ 125.031931] [<ffffffff81631969>] schedule+0x29/0x70 Aug 21 20:37:46 fambox kernel: [ 125.031933] [<ffffffff81631a3f>] io_schedule+0x8f/0xd0 Aug 21 20:37:46 fambox kernel: [ 125.031936] [<ffffffff811b25de>] sleep_on_buffer+0xe/0x20 Aug 21 20:37:46 fambox kernel: [ 125.031938] [<ffffffff8163023f>] __wait_on_bit+0x5f/0x90 Aug 21 20:37:46 fambox kernel: [ 125.031941] [<ffffffff812b0d67>] ? submit_bio+0x87/0x110 Aug 21 20:37:46 fambox kernel: [ 125.031943] [<ffffffff811b25d0>] ? __wait_on_buffer+0x30/0x30 Aug 21 20:37:46 fambox kernel: [ 125.031945] [<ffffffff816302ec>] out_of_line_wait_on_bit+0x7c/0x90 Aug 21 20:37:46 fambox kernel: [ 125.031950] [<ffffffff8107b870>] ? autoremove_wake_function+0x40/0x40 Aug 21 20:37:46 fambox kernel: [ 125.031953] [<ffffffff811b25ce>] __wait_on_buffer+0x2e/0x30 Aug 21 20:37:46 fambox kernel: [ 125.031971] [<ffffffffa0068628>] ext4_wait_block_bitmap+0xc8/0xd0 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.031983] [<ffffffffa00a29de>] ext4_mb_init_cache+0x1de/0x710 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.031986] [<ffffffff8112950c>] ? add_to_page_cache_locked+0xac/0xf0 Aug 21 20:37:46 fambox kernel: [ 125.031989] [<ffffffff81129585>] ? add_to_page_cache_lru+0x35/0x50 Aug 21 20:37:46 fambox kernel: [ 125.031998] [<ffffffffa00a305e>] ext4_mb_init_group+0x14e/0x200 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032006] [<ffffffffa00a3260>] ext4_mb_good_group+0x150/0x160 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032014] [<ffffffffa00a52d9>] ext4_mb_regular_allocator+0x1a9/0x430 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032022] [<ffffffffa00a6eed>] ext4_mb_new_blocks+0x40d/0x560 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032024] [<ffffffff8163284e>] ? _raw_spin_lock+0xe/0x20 Aug 21 20:37:46 fambox kernel: [ 125.032033] [<ffffffffa0098a0e>] ? ext4_ext_put_in_cache+0x6e/0xf0 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032041] [<ffffffffa009d218>] ext4_ext_map_blocks+0xe28/0x1c80 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032049] [<ffffffffa0076438>] ? ext4_io_submit+0x38/0x60 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032056] [<ffffffffa0070095>] ext4_map_blocks+0x1f5/0x2c0 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032064] [<ffffffffa0074336>] mpage_da_map_and_submit+0xb6/0x480 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032066] [<ffffffff811292ab>] ? find_get_pages_tag+0xcb/0x170 Aug 21 20:37:46 fambox kernel: [ 125.032073] [<ffffffffa0074760>] mpage_add_bh_to_extent+0x60/0xe0 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032080] [<ffffffffa0074ae1>] write_cache_pages_da+0x301/0x450 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032088] [<ffffffffa0074f80>] ext4_da_writepages+0x350/0x620 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032091] [<ffffffff81134af0>] do_writepages+0x20/0x40 Aug 21 20:37:46 fambox kernel: [ 125.032093] [<ffffffff81129f09>] __filemap_fdatawrite_range+0x59/0x60 Aug 21 20:37:46 fambox kernel: [ 125.032096] [<ffffffff81129f62>] filemap_write_and_wait_range+0x52/0x80 Aug 21 20:37:46 fambox kernel: [ 125.032103] [<ffffffffa006ae5f>] ext4_sync_file+0x6f/0x3d0 [ext4] Aug 21 20:37:46 fambox kernel: [ 125.032106] [<ffffffff811b01fb>] vfs_fsync+0x2b/0x40 Aug 21 20:37:46 fambox kernel: [ 125.032108] [<ffffffff811594e4>] sys_msync+0x144/0x1d0 Aug 21 20:37:46 fambox kernel: [ 125.032111] [<ffffffff8163ad69>] system_call_fastpath+0x16/0x1b Aug 21 20:37:46 fambox kernel: [ 125.032113] Aug 21 20:37:46 fambox kernel: [ 125.032113] Restarting tasks ... done. Aug 21 20:37:46 fambox kernel: [ 125.041062] video LNXVIDEO:00: Restoring backlight state Aug 21 20:37:47 fambox kernel: [ 125.989548] iwlwifi 0000:01:00.0: L1 Enabled; Disabling L0S Aug 21 20:37:47 fambox kernel: [ 125.996358] iwlwifi 0000:01:00.0: Radio type=0x1-0x2-0x0 Aug 21 20:37:47 fambox kernel: [ 126.110563] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready Aug 21 20:37:48 fambox kernel: [ 126.345514] cfg80211: Found new beacon on frequency: 2467 MHz (Ch 12) on phy0 Aug 21 20:37:51 fambox kernel: [ 129.623635] cfg80211: Found new beacon on frequency: 2472 MHz (Ch 13) on phy0 Aug 21 20:37:54 fambox kernel: [ 132.397807] wlan0: authenticate with 00:04:0e:e4:00:3d Aug 21 20:37:54 fambox kernel: [ 132.405565] wlan0: send auth to 00:04:0e:e4:00:3d (try 1/3) Aug 21 20:37:54 fambox kernel: [ 132.407357] wlan0: authenticated Aug 21 20:37:54 fambox kernel: [ 132.407555] iwlwifi 0000:01:00.0: wlan0: disabling HT as WMM/QoS is not supported by the AP Aug 21 20:37:54 fambox kernel: [ 132.407560] iwlwifi 0000:01:00.0: wlan0: disabling VHT as WMM/QoS is not supported by the AP Aug 21 20:37:54 fambox kernel: [ 132.410517] wlan0: associate with 00:04:0e:e4:00:3d (try 1/3) Aug 21 20:37:54 fambox kernel: [ 132.414334] wlan0: RX AssocResp from 00:04:0e:e4:00:3d (capab=0x411 status=0 aid=2) Aug 21 20:37:54 fambox kernel: [ 132.418449] wlan0: associated Aug 21 20:37:54 fambox kernel: [ 132.418489] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
