On 11/06/2015 05:08 AM, Thomas Gleixner wrote: [..]
Now my question is how big is the induced latency.
Here is one such trace we've captured. --- cyclictest-2345 [002] 73.674891: hrtimer_init: hrtimer=0xffff8800b5b1feb8 clockid=CLOCK_MONOTONIC mode=HRTIMER_MODE_ABS cyclictest-2345 [002] 73.674891: function: do_nanosleep cyclictest-2345 [002] 73.674891: function: __hrtimer_start_range_ns cyclictest-2345 [002] 73.674891: function: lock_hrtimer_base.isra.24 cyclictest-2345 [002] 73.674891: function: _raw_spin_lock_irqsave cyclictest-2345 [002] 73.674891: function: enqueue_hrtimer cyclictest-2345 [002] 73.674891: hrtimer_start: hrtimer=0xffff8800b5b1feb8 function=hrtimer_wakeup expires=73712055622 softexpires=73712055622 ... ... avahi-daemon-1385 [002] 73.675075: function: e1000e_set_rx_mode avahi-daemon-1385 [002] 73.675078: function: __kmalloc avahi-daemon-1385 [002] 73.675079: function: kmalloc_slab avahi-daemon-1385 [002] 73.675079: function: e1000e_update_mc_addr_list_generic avahi-daemon-1385 [002] 73.675080: bputs: e1000e_update_mc_addr_list_generic: replace MTA table avahi-daemon-1385 [002] 73.675159: function: smp_apic_timer_interrupt avahi-daemon-1385 [002] 73.675159: function: irq_enter avahi-daemon-1385 [002] 73.675159: function: rcu_irq_enter avahi-daemon-1385 [002] 73.675159: function: exit_idle avahi-daemon-1385 [002] 73.675159: function: local_apic_timer_interrupt avahi-daemon-1385 [002] 73.675159: function: hrtimer_interrupt avahi-daemon-1385 [002] 73.675159: function: _raw_spin_lock avahi-daemon-1385 [002] 73.675159: function: ktime_get_update_offsets avahi-daemon-1385 [002] 73.675159: function: __run_hrtimer avahi-daemon-1385 [002] 73.675160: hrtimer_cancel: hrtimer=0xffff8800b5b1feb8 avahi-daemon-1385 [002] 73.675160: function: __remove_hrtimer avahi-daemon-1385 [002] 73.675160: hrtimer_expire_entry: hrtimer=0xffff8800b5b1feb8 now=73712084997 function=hrtimer_wakeup/0x0 --- After the wake-up timer is armed, the e1000e driver handles the network link configuration after the NIC was reset. When the function "e1000e_update_mc_addr_list_generic" is called, the MTA table is rewritten (the writing of this table consists of >70 MMIO writes followed by a read). We see the hrtimer entry expire at the value 73712084997 near the bottom of the trace. 73712084997ns - 73712055622ns = 29375ns So, we see a ~29us latency, in comparison to a good case where we see about 1us. Consistently, when we've seen large cyclictest latencies, we see that the e1000e driver calls a function which uses e1e_flush after a large series of writes. - JD -- To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
