From: Ivo Sieben <meltedpianoman@gmail.com>
To: Greg KH <gregkh@linuxfoundation.org>,
linux-serial@vger.kernel.org, Alan Cox <alan@linux.intel.com>,
RT <linux-rt-users@vger.kernel.org>
Subject: Re: Deterministic behavior for TTY serial
Date: Wed, 2 May 2012 10:38:22 +0200 [thread overview]
Message-ID: <CAMSQXEHHOHeNYPJZT0b4s62T3uuNXSt9WucSrGOTfjXOU_guzg@mail.gmail.com> (raw)
In-Reply-To: <CAMSQXEHAyPOF6YghsYmqqyx+N0oMgn5E=znhgFyspMUnaH78ig@mail.gmail.com>
Sorry, now my responce with send to all instead of only to Alan....
2012/5/2 Ivo Sieben <meltedpianoman@gmail.com>:
> Hi,
>
>> It's a spin lock and its only held across very small numbers of
>> instructions in any normal path so this rather surprises me - in your
>> actual capture data can you see what is holding the lock for long times
>> causing this ?
>
> Indeed the lock is only taken for a very short time. So in most
> situations it works fine, the lock is free, and can be taken quickly.
> But when I stress my system (e.g. by continuously dumpling a lot of
> text data to another serial terminal from the background), my high
> priority task sometimes finds the lock is taken. In that case
> additional lock handling comes in: priority inheritance, a context
> switch to the background task that holds the lock, and a context
> switch back after the lock is released again. This makes a normal read
> that takes about 50us, to increase in execution time to 150us.
>
> The ftrace for a "quick" spin lock:
>
> 0) | tty_ldisc_deref() {
> 0) | put_ldisc() {
> 0) 8.960 us | atomic_dec_and_spin_lock();
> 0) | __wake_up() {
> 0) | rt_spin_lock() {
> 0) | rt_spin_lock_slowlock() {
> 0) 8.720 us | __try_to_take_rt_mutex();
> 0) + 25.360 us | }
> 0) + 41.760 us | }
> 0) 8.400 us | __wake_up_common();
> 0) | rt_spin_unlock() {
> 0) 8.240 us | rt_spin_lock_slowunlock();
> 0) + 24.320 us | }
> 0) ! 107.840 us | }
> 0) ! 146.400 us | }
> 0) ! 163.120 us | }
>
> While the ftrace for a spin lock that is already taken is a lot
> longer, adding a lot of execution time.
>
> 0) | tty_ldisc_deref() {
> 0) | put_ldisc() {
> 0) 8.640 us | atomic_dec_and_spin_lock();
> 0) | __wake_up() {
> 0) | rt_spin_lock() {
> 0) | rt_spin_lock_slowlock() {
> 0) 8.160 us | __try_to_take_rt_mutex();
> 0) | task_blocks_on_rt_mutex() {
> 0) 8.720 us | __rt_mutex_adjust_prio();
> 0) | __rt_mutex_adjust_prio() {
> 0) | task_setprio() {
> 0) | dequeue_task() {
> 0) 9.680 us | update_rq_clock();
> 0) | dequeue_task_rt() {
> 0) 9.200 us | update_curr_rt();
> 0) + 10.400 us | dequeue_rt_stack();
> 0) + 44.560 us | }
> 0) + 80.000 us | }
> 0) | enqueue_task() {
> 0) 9.120 us | update_rq_clock();
> 0) | enqueue_task_rt() {
> 0) 8.400 us | dequeue_rt_stack();
> 0) 9.280 us | __enqueue_rt_entity();
> 0) + 42.240 us | }
> 0) + 75.840 us | }
> 0) 8.560 us | prio_changed_rt();
> 0) 8.000 us | __task_rq_unlock();
> 0) ! 216.240 us | }
> 0) ! 233.280 us | }
> 0) ! 271.360 us | }
> 0) 8.160 us | __try_to_take_rt_mutex();
> 0) | schedule() {
> 0) | __schedule() {
> 0) | rcu_note_context_switch() {
> 0) 9.120 us | rcu_preempt_note_context_switch();
> 0) + 25.920 us | }
> 0) | deactivate_task() {
> 0) | dequeue_task() {
> 0) 9.120 us | update_rq_clock();
> 0) | dequeue_task_rt() {
> 0) 8.400 us | update_curr_rt();
> 0) 8.720 us | dequeue_rt_stack();
> 0) + 40.880 us | }
> 0) + 74.480 us | }
> 0) + 91.200 us | }
> 0) | put_prev_task_rt() {
> 0) 8.480 us | update_curr_rt();
> 0) + 24.560 us | }
> 0) 8.000 us | pick_next_task_stop();
> 0) | pick_next_task_rt() {
> 0) 8.560 us | pick_next_rt_entity();
> 0) + 25.280 us | }
> 0) ==========> |
> 0) | asm_do_IRQ() {
> 0) | irq_enter() {
> 0) 8.320 us | idle_cpu();
> 0) + 24.160 us | }
> 0) | generic_handle_irq() {
> 0) | handle_level_irq() {
> 0) 8.240 us | at91_aic_mask_irq();
> 0) 8.160 us | at91_aic_mask_irq();
> 0) | handle_irq_event() {
> 0) | handle_irq_event_percpu() {
> 0) | periodic_tick_interrupt() {
> 0) | roserts_timer_hook() {
> 0) |
> system_timer_get_highres_time() {
> 0) 10.000 us | __get_fpga_time_64();
> 0) + 26.880 us | }
> 0) + 43.920 us | }
> 0) + 61.520 us | }
> 0) 8.480 us | note_interrupt();
> 0) + 96.320 us | }
> 0) ! 113.200 us | }
> 0) | unmask_irq() {
> 0) 8.160 us | at91_aic_unmask_irq();
> 0) + 24.240 us | }
> 0) ! 195.840 us | }
> 0) ! 212.080 us | }
> 0) 8.800 us | irq_exit();
> 0) ! 278.240 us | }
> 0) <========== |
> 0) | atomic_notifier_call_chain() {
> 0) | __atomic_notifier_call_chain() {
> 0) 8.240 us | __rcu_read_lock();
> 0) 8.400 us | notifier_call_chain();
> 0) 8.480 us | __rcu_read_unlock();
> 0) + 58.080 us | }
> 0) + 75.920 us | }
> ------------------------------------------
> 0) uart_to-493 => ksoftir-3
> ------------------------------------------
>
> 0) + 10.640 us | finish_task_switch();
> 0) | rt_spin_unlock() {
> 0) | rt_spin_lock_slowunlock() {
> 0) | wakeup_next_waiter() {
> 0) | wake_up_lock_sleeper() {
> 0) | try_to_wake_up() {
> 0) | activate_task() {
> 0) | enqueue_task() {
> 0) 9.120 us | update_rq_clock();
> 0) | enqueue_task_rt() {
> 0) 8.240 us | dequeue_rt_stack();
> 0) 8.080 us | __enqueue_rt_entity();
> 0) + 39.360 us | }
> 0) + 71.840 us | }
> 0) + 87.760 us | }
> 0) | ttwu_do_wakeup() {
> 0) | check_preempt_curr() {
> 0) 7.840 us | check_preempt_curr_rt();
> 0) + 24.320 us | }
> 0) + 43.520 us | }
> 0) ! 156.960 us | }
> 0) ! 172.960 us | }
> 0) ! 190.080 us | }
> 0) | rt_mutex_adjust_prio() {
> 0) | __rt_mutex_adjust_prio() {
> 0) | task_setprio() {
> 0) | dequeue_task() {
> 0) 8.480 us | update_rq_clock();
> 0) | dequeue_task_rt() {
> 0) 8.880 us | update_curr_rt();
> 0) 8.080 us | dequeue_rt_stack();
> 0) + 39.920 us | }
> 0) + 72.000 us | }
> 0) | put_prev_task_rt() {
> 0) + 12.800 us | update_curr_rt();
> 0) + 28.000 us | }
> 0) 7.600 us | set_curr_task_rt();
> 0) | enqueue_task() {
> 0) 8.560 us | update_rq_clock();
> 0) | enqueue_task_rt() {
> 0) 7.760 us | dequeue_rt_stack();
> 0) 7.920 us | __enqueue_rt_entity();
> 0) + 38.160 us | }
> 0) + 69.440 us | }
> 0) 7.920 us | prio_changed_rt();
> 0) 8.240 us | __task_rq_unlock();
> 0) ! 249.760 us | }
> 0) ! 265.600 us | }
> 0) | __schedule() {
> 0) | rcu_note_context_switch() {
> 0) 8.800 us | rcu_preempt_note_context_switch();
> 0) + 25.200 us | }
> 0) 9.360 us | update_rq_clock();
> 0) | put_prev_task_rt() {
> 0) 8.560 us | update_curr_rt();
> 0) + 24.720 us | }
> 0) 8.160 us | pick_next_task_stop();
> 0) | pick_next_task_rt() {
> 0) 8.560 us | pick_next_rt_entity();
> 0) + 24.880 us | }
> 0) | atomic_notifier_call_chain() {
> 0) | __atomic_notifier_call_chain() {
> 0) 7.600 us | __rcu_read_lock();
> 0) 7.760 us | notifier_call_chain();
> 0) 7.920 us | __rcu_read_unlock();
> 0) + 53.760 us | }
> 0) + 69.200 us | }
> ------------------------------------------
> 0) ksoftir-3 => uart_to-493
> ------------------------------------------
>
> 0) + 10.080 us | finish_task_switch();
> 0) ! 1381.120 us | }
> 0) ! 1397.680 us | } /* schedule */
> 0) + 10.320 us | __try_to_take_rt_mutex();
> 0) ! 1748.240 us | } /* rt_spin_lock_slowlock */
> 0) ! 1764.320 us | } /* rt_spin_lock */
> 0) 8.400 us | __wake_up_common();
> 0) | rt_spin_unlock() {
> 0) 8.160 us | rt_spin_lock_slowunlock();
> 0) + 24.320 us | }
> 0) ! 1830.720 us | } /* __wake_up */
> 0) ! 1864.960 us | } /* put_ldisc */
> 0) ! 1881.760 us | } /* tty_ldisc_deref */
next prev parent reply other threads:[~2012-05-02 8:38 UTC|newest]
Thread overview: 13+ messages / expand[flat|nested] mbox.gz Atom feed top
2012-04-17 14:38 Deterministic behavior for TTY serial Ivo Sieben
2012-04-19 0:14 ` Greg KH
2012-04-19 15:37 ` Ivo Sieben
2012-04-19 15:46 ` Greg KH
2012-04-26 14:27 ` Ivo Sieben
2012-05-01 14:30 ` Ivo Sieben
2012-05-01 15:04 ` Alan Cox
[not found] ` <CAMSQXEHAyPOF6YghsYmqqyx+N0oMgn5E=znhgFyspMUnaH78ig@mail.gmail.com>
2012-05-02 8:38 ` Ivo Sieben [this message]
2012-05-02 12:39 ` Ivo Sieben
2012-05-03 15:28 ` Ivo Sieben
2012-05-05 0:32 ` Greg KH
2012-04-19 11:19 ` Alan Cox
2012-04-19 15:42 ` Ivo Sieben
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=CAMSQXEHHOHeNYPJZT0b4s62T3uuNXSt9WucSrGOTfjXOU_guzg@mail.gmail.com \
--to=meltedpianoman@gmail.com \
--cc=alan@linux.intel.com \
--cc=gregkh@linuxfoundation.org \
--cc=linux-rt-users@vger.kernel.org \
--cc=linux-serial@vger.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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.