From: "Rafael J. Wysocki" <rafael.j.wysocki@intel.com>
To: I@cmpxchg.org, Oliver Winker <oliverml1@oli1170.net>
Cc: Jan Kara <jack@suse.cz>,
Andrew Morton <akpm@linux-foundation.org>,
bugzilla-daemon@bugzilla.kernel.org, linux-mm@kvack.org,
Maxim Patlasov <mpatlasov@parallels.com>,
Fengguang Wu <fengguang.wu@intel.com>, Tejun Heo <tj@kernel.org>
Subject: Re: [Bug 75101] New: [bisected] s2disk / hibernate blocks on "Saving 506031 image data pages () ..."
Date: Tue, 06 May 2014 01:45:01 +0200 [thread overview]
Message-ID: <5368227D.7060302@intel.com> (raw)
In-Reply-To: <20140505233358.GC19914@cmpxchg.org>
On 5/6/2014 1:33 AM, Johannes Weiner wrote:
> Hi Oliver,
>
> On Mon, May 05, 2014 at 11:00:13PM +0200, Oliver Winker wrote:
>> Hello,
>>
>> 1) Attached a full function-trace log + other SysRq outputs, see [1]
>> attached.
>>
>> I saw bdi_...() calls in the s2disk paths, but didn't check in detail
>> Probably more efficient when one of you guys looks directly.
> Thanks, this looks interesting. balance_dirty_pages() wakes up the
> bdi_wq workqueue as it should:
>
> [ 249.148009] s2disk-3327 2.... 48550413us : global_dirty_limits <-balance_dirty_pages_ratelimited
> [ 249.148009] s2disk-3327 2.... 48550414us : global_dirtyable_memory <-global_dirty_limits
> [ 249.148009] s2disk-3327 2.... 48550414us : writeback_in_progress <-balance_dirty_pages_ratelimited
> [ 249.148009] s2disk-3327 2.... 48550414us : bdi_start_background_writeback <-balance_dirty_pages_ratelimited
> [ 249.148009] s2disk-3327 2.... 48550414us : mod_delayed_work_on <-balance_dirty_pages_ratelimited
> [ 249.148009] s2disk-3327 2.... 48550414us : try_to_grab_pending <-mod_delayed_work_on
> [ 249.148009] s2disk-3327 2d... 48550414us : del_timer <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550415us : get_work_pool <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550415us : _raw_spin_lock <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550415us : get_work_pwq <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550415us : pwq_activate_delayed_work <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550415us : get_work_pwq <-pwq_activate_delayed_work
> [ 249.148009] s2disk-3327 2d... 48550415us : move_linked_works <-pwq_activate_delayed_work
> [ 249.148009] s2disk-3327 2d... 48550415us : get_work_pwq <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550416us : pwq_dec_nr_in_flight <-try_to_grab_pending
> [ 249.148009] s2disk-3327 2d... 48550416us : __queue_delayed_work <-mod_delayed_work_on
> [ 249.148009] s2disk-3327 2d... 48550416us : __queue_work <-mod_delayed_work_on
> [ 249.148009] s2disk-3327 2d... 48550416us : get_work_pool <-__queue_work
> [ 249.148009] s2disk-3327 2d... 48550416us : _raw_spin_lock <-__queue_work
> [ 249.148009] s2disk-3327 2d... 48550416us : insert_work <-__queue_work
> [ 249.148009] s2disk-3327 2d... 48550417us : get_pwq.isra.20 <-insert_work
> [ 249.148009] s2disk-3327 2d... 48550417us : wake_up_worker <-__queue_work
> [ 249.148009] s2disk-3327 2d... 48550417us : wake_up_process <-__queue_work
> [ 249.148009] s2disk-3327 2d... 48550417us : try_to_wake_up <-__queue_work
> [ 249.148009] s2disk-3327 2d... 48550417us : _raw_spin_lock_irqsave <-try_to_wake_up
> [ 249.148009] s2disk-3327 2d... 48550417us : task_waking_fair <-try_to_wake_up
> [ 249.148009] s2disk-3327 2d... 48550418us : select_task_rq_fair <-select_task_rq
> [ 249.148009] s2disk-3327 2d... 48550418us : idle_cpu <-select_task_rq_fair
> [ 249.148009] s2disk-3327 2d... 48550418us : idle_cpu <-select_task_rq_fair
> [ 249.148009] s2disk-3327 2d... 48550418us : cpus_share_cache <-try_to_wake_up
> [ 249.148009] s2disk-3327 2d... 48550418us : _raw_spin_lock <-try_to_wake_up
> [ 249.148009] s2disk-3327 2d... 48550419us : ttwu_do_activate.constprop.100 <-try_to_wake_up
> [ 249.148009] s2disk-3327 2d... 48550419us : activate_task <-ttwu_do_activate.constprop.100
> [ 249.148009] s2disk-3327 2d... 48550419us : enqueue_task <-ttwu_do_activate.constprop.100
> [ 249.148009] s2disk-3327 2d... 48550419us : update_rq_clock <-enqueue_task
> [ 249.148009] s2disk-3327 2d... 48550419us : enqueue_task_fair <-ttwu_do_activate.constprop.100
> [ 249.148009] s2disk-3327 2d... 48550419us : update_curr <-enqueue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550420us : update_min_vruntime <-update_curr
> [ 249.148009] s2disk-3327 2d... 48550420us : __compute_runnable_contrib.part.55 <-update_entity_load_avg
> [ 249.148009] s2disk-3327 2d... 48550420us : update_cfs_rq_blocked_load <-enqueue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550420us : account_entity_enqueue <-enqueue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550420us : update_cfs_shares <-enqueue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550420us : __enqueue_entity <-enqueue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550421us : hrtick_update <-ttwu_do_activate.constprop.100
> [ 249.148009] s2disk-3327 2d... 48550421us : wq_worker_waking_up <-ttwu_do_activate.constprop.100
> [ 249.148009] s2disk-3327 2d... 48550421us : kthread_data <-wq_worker_waking_up
> [ 249.148009] s2disk-3327 2d... 48550421us : ttwu_do_wakeup <-try_to_wake_up
> [ 249.148009] s2disk-3327 2d... 48550421us : check_preempt_curr <-ttwu_do_wakeup
> [ 249.148009] s2disk-3327 2d... 48550421us : check_preempt_wakeup <-check_preempt_curr
> [ 249.148009] s2disk-3327 2d... 48550422us : update_curr <-check_preempt_wakeup
> [ 249.148009] s2disk-3327 2d... 48550422us : wakeup_preempt_entity.isra.53 <-check_preempt_wakeup
> [ 249.148009] s2disk-3327 2d... 48550422us : _raw_spin_unlock_irqrestore <-try_to_wake_up
> [ 249.148009] s2disk-3327 2.... 48550423us : bdi_dirty_limit <-bdi_dirty_limits
> [ 249.148009] s2disk-3327 2d... 48550423us : _raw_spin_lock_irqsave <-__percpu_counter_sum
> [ 249.148009] s2disk-3327 2d... 48550423us : _raw_spin_unlock_irqrestore <-__percpu_counter_sum
> [ 249.148009] s2disk-3327 2d... 48550423us : _raw_spin_lock_irqsave <-__percpu_counter_sum
> [ 249.148009] s2disk-3327 2d... 48550424us : _raw_spin_unlock_irqrestore <-__percpu_counter_sum
> [ 249.148009] s2disk-3327 2.... 48550424us : bdi_position_ratio <-balance_dirty_pages_ratelimited
> [ 249.148009] s2disk-3327 2.... 48550424us : io_schedule_timeout <-balance_dirty_pages_ratelimited
> [ 249.148009] s2disk-3327 2.... 48550424us : __delayacct_blkio_start <-io_schedule_timeout
> [ 249.148009] s2disk-3327 2.... 48550424us : ktime_get_ts <-io_schedule_timeout
> [ 249.148009] s2disk-3327 2.... 48550424us : blk_flush_plug_list <-io_schedule_timeout
> [ 249.148009] s2disk-3327 2.... 48550425us : schedule_timeout <-io_schedule_timeout
> [ 249.148009] s2disk-3327 2.... 48550425us : lock_timer_base.isra.35 <-__mod_timer
> [ 249.148009] s2disk-3327 2.... 48550425us : _raw_spin_lock_irqsave <-lock_timer_base.isra.35
> [ 249.148009] s2disk-3327 2d... 48550425us : detach_if_pending <-__mod_timer
> [ 249.148009] s2disk-3327 2d... 48550425us : idle_cpu <-__mod_timer
> [ 249.148009] s2disk-3327 2d... 48550425us : internal_add_timer <-__mod_timer
> [ 249.148009] s2disk-3327 2d... 48550425us : __internal_add_timer <-internal_add_timer
> [ 249.148009] s2disk-3327 2d... 48550426us : _raw_spin_unlock_irqrestore <-__mod_timer
> [ 249.148009] s2disk-3327 2.... 48550426us : schedule <-schedule_timeout
> [ 249.148009] s2disk-3327 2.... 48550426us : __schedule <-schedule_timeout
> [ 249.148009] s2disk-3327 2.... 48550426us : rcu_note_context_switch <-__schedule
> [ 249.148009] s2disk-3327 2.... 48550426us : rcu_sched_qs <-rcu_note_context_switch
> [ 249.148009] s2disk-3327 2.... 48550426us : _raw_spin_lock_irq <-__schedule
> [ 249.148009] s2disk-3327 2d... 48550427us : deactivate_task <-__schedule
> [ 249.148009] s2disk-3327 2d... 48550427us : dequeue_task <-__schedule
> [ 249.148009] s2disk-3327 2d... 48550427us : update_rq_clock <-dequeue_task
> [ 249.148009] s2disk-3327 2d... 48550427us : dequeue_task_fair <-__schedule
> [ 249.148009] s2disk-3327 2d... 48550427us : update_curr <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550427us : update_min_vruntime <-update_curr
> [ 249.148009] s2disk-3327 2d... 48550427us : cpuacct_charge <-update_curr
> [ 249.148009] s2disk-3327 2d... 48550428us : update_cfs_rq_blocked_load <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550428us : clear_buddies <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550428us : account_entity_dequeue <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550428us : update_min_vruntime <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550428us : update_cfs_shares <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550428us : update_curr <-update_cfs_shares
> [ 249.148009] s2disk-3327 2d... 48550429us : update_min_vruntime <-update_curr
> [ 249.148009] s2disk-3327 2d... 48550429us : account_entity_dequeue <-update_cfs_shares
> [ 249.148009] s2disk-3327 2d... 48550429us : account_entity_enqueue <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550429us : update_curr <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550429us : update_cfs_rq_blocked_load <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550429us : clear_buddies <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550429us : account_entity_dequeue <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550430us : update_min_vruntime <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550430us : update_cfs_shares <-dequeue_task_fair
> [ 249.148009] s2disk-3327 2d... 48550430us : hrtick_update <-__schedule
> [ 249.148009] s2disk-3327 2d... 48550430us : put_prev_task_fair <-__schedule
> [ 249.148009] s2disk-3327 2d... 48550430us : pick_next_task_fair <-pick_next_task
> [ 249.148009] s2disk-3327 2d... 48550430us : clear_buddies <-pick_next_task_fair
> [ 249.148009] s2disk-3327 2d... 48550431us : __dequeue_entity <-pick_next_task_fair
>
> but the worker wakeup doesn't actually do anything:
>
> [ 249.148009] kworker/-3466 2d... 48550431us : finish_task_switch <-__schedule
> [ 249.148009] kworker/-3466 2.... 48550431us : _raw_spin_lock_irq <-worker_thread
> [ 249.148009] kworker/-3466 2d... 48550431us : need_to_create_worker <-worker_thread
> [ 249.148009] kworker/-3466 2d... 48550432us : worker_enter_idle <-worker_thread
> [ 249.148009] kworker/-3466 2d... 48550432us : too_many_workers <-worker_enter_idle
> [ 249.148009] kworker/-3466 2.... 48550432us : schedule <-worker_thread
> [ 249.148009] kworker/-3466 2.... 48550432us : __schedule <-worker_thread
>
> My suspicion is that this fails because the bdi_wq is frozen at this
> point and so the flush work never runs until resume, whereas before my
> patch the effective dirty limit was high enough so that image could be
> written in one go without being throttled; followed by an fsync() that
> then writes the pages in the context of the unfrozen s2disk.
>
> Does this make sense? Rafael? Tejun?
Well, it does seem to make sense to me.
Thanks,
Rafael
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>
next prev parent reply other threads:[~2014-05-05 23:45 UTC|newest]
Thread overview: 22+ messages / expand[flat|nested] mbox.gz Atom feed top
2014-05-05 23:33 [Bug 75101] New: [bisected] s2disk / hibernate blocks on "Saving 506031 image data pages () ..." Johannes Weiner
2014-05-05 23:45 ` Rafael J. Wysocki [this message]
2014-06-12 22:02 ` Johannes Weiner
2014-06-12 23:50 ` Rafael J. Wysocki
2014-06-13 4:55 ` Johannes Weiner
2014-06-16 16:29 ` Rafael J. Wysocki
2019-04-02 23:25 ` Andrew Morton
2019-04-03 3:54 ` Matheus Fillipe
2019-04-03 8:23 ` Rainer Fiebig
2019-04-03 8:34 ` Rainer Fiebig
2019-04-03 9:34 ` Jan Kara
2019-04-03 10:04 ` Rainer Fiebig
2019-04-03 16:59 ` Matheus Fillipe
2019-04-03 17:55 ` Rainer Fiebig
2019-04-03 19:08 ` Matheus Fillipe
[not found] ` <CAFWuBvfxS0S6me_pneXmNzKwObSRUOg08_7=YToAoBg53UtPKg@mail.gmail.com>
2019-04-04 10:48 ` Rainer Fiebig
2019-04-04 16:04 ` matheus
2019-04-03 21:43 ` Rafael J. Wysocki
[not found] <bug-75101-27@https.bugzilla.kernel.org/>
2014-04-29 22:24 ` Andrew Morton
2014-05-05 15:35 ` Johannes Weiner
2014-05-05 16:10 ` Jan Kara
2014-05-05 21:00 ` Oliver Winker
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=5368227D.7060302@intel.com \
--to=rafael.j.wysocki@intel.com \
--cc=I@cmpxchg.org \
--cc=akpm@linux-foundation.org \
--cc=bugzilla-daemon@bugzilla.kernel.org \
--cc=fengguang.wu@intel.com \
--cc=jack@suse.cz \
--cc=linux-mm@kvack.org \
--cc=mpatlasov@parallels.com \
--cc=oliverml1@oli1170.net \
--cc=tj@kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).