Re: libata/sata_nv latency on NVIDIA CK804 [was Re: AMD64 X2 lost ticks on PM timer]

From: Bill Rugolsky Jr.
Date: Thu Mar 16 2006 - 11:55:15 EST

Next message: Srivatsa Vaddagiri: "Re: cpu_exclusive feature of cpuset broken?"
Previous message: Jes Sorensen: "[patch] mspec - special memory driver and do_no_pfn handler"
In reply to: Alan Cox: "Re: libata/sata_nv latency on NVIDIA CK804 [was Re: AMD64 X2 lostticks on PM timer]"
Next in thread: Andi Kleen: "Re: libata/sata_nv latency on NVIDIA CK804 [was Re: AMD64 X2 lost ticks on PM timer]"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Thu, Mar 16, 2006 at 03:13:39PM +0000, Alan Cox wrote:
> On Mer, 2006-03-15 at 23:00 +0100, Ingo Molnar wrote:
> > so my guess would be that this device doesnt do MMIO, and the PIO inb()
> > causes some bad BIOS-based SMM handler/emulator to trigger, which takes
> > 16.6 msecs. If indeed the device is not in MMIO mode, is there a way to
> > force it into MMIO mode, to test this theory?
>
> There is a much more reliable way to check this. Use the profiling
> registers to check the instruction issue count before/after the I/O and
> you'll know if its something like SMM or just a bus stall.

Brilliant [as usual 8-)].

So I imagine that the thing to do is just insert before/after
rdmsr(MSR_K7_PERFCTR[0123]) into the code, with a suitable printk(),
and then program the counters with oprofile to use large event
counts (lasting seconds)? The -rt patch could make good use of some
infrastructure for doing this.

> I can believe the bus stall because some devices will queue a large FIFO
> of data for the disk and the status read may require flushing it all
> out.

It may involve synchronous writes.

I did as Ingo suggested, and added the before/after mcount()s:

diff -up drivers/scsi/libata-core.c{.orig,}
--- drivers/scsi/libata-core.c.orig 2006-03-15 17:19:42.000000000 -0500
+++ drivers/scsi/libata-core.c 2006-03-16 10:08:32.000000000 -0500
@@ -3984,8 +3984,11 @@ u8 ata_bmdma_status(struct ata_port *ap)
if (ap->flags & ATA_FLAG_MMIO) {
void __iomem *mmio = (void __iomem *) ap->ioaddr.bmdma_addr;
host_stat = readb(mmio + ATA_DMA_STATUS);
- } else
+ } else {
+ mcount();
host_stat = inb(ap->ioaddr.bmdma_addr + ATA_DMA_STATUS);
+ mcount();
+ }
return host_stat;
}

This produced the trace below in < 30 seconds, which clearly indicates
that the inb() is a problem. This occurs when running

tar cf /dev/zero /usr & tar cf /dev/zero /extra_disk &

with both of them mounted readonly. HOWEVER - I'm an idiot - I just
realized that syslog is sitting there synchronously writing lost tick
messages into the log on the same disks. So I turned off syslog and the
trace became much harder to reproduce. After several minutes I got one.

+1 for Alan's theory about flushes stalling status reads.

-Bill

preemption latency trace v1.1.5 on 2.6.16-rc6-git4-profile
--------------------------------------------------------------------
latency: 1861 us, #730/730, CPU#0 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:1)
-----------------
| task: rtpserver-3032 (uid:316 nice:-10 policy:0 rt_prio:0)
-----------------

_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
<idle>-0 0dns. 0us : __trace_start_sched_wakeup (try_to_wake_up)
<idle>-0 0dns. 0us : __trace_start_sched_wakeup <<...>-3032> (69 0)
<idle>-0 0dns. 0us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dns. 0us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 0us : do_IRQ (ret_from_intr)
<idle>-0 0dns. 0us : exit_idle (do_IRQ)
<idle>-0 0dns. 0us : in_lock_functions (add_preempt_count)
<idle>-0 0dnH. 0us : __do_IRQ (do_IRQ)
<idle>-0 0dnH. 0us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1us : mask_and_ack_level_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1us : handle_IRQ_event (__do_IRQ)
<idle>-0 0dnH. 1us : nv_interrupt (handle_IRQ_event)
<idle>-0 0dnH. 1us : _spin_lock_irqsave (nv_interrupt)
<idle>-0 0dnH. 1us : ata_host_intr (nv_interrupt)
<idle>-0 0dnH. 1us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 1us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 2us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 2us : ata_bmdma_stop (ata_host_intr)
<idle>-0 0dnH. 2us : ata_altstatus (ata_bmdma_stop)
<idle>-0 0dnH. 2us : ata_altstatus (ata_host_intr)
<idle>-0 0dnH. 3us : ata_check_status (ata_host_intr)
<idle>-0 0dnH. 3us : ata_bmdma_irq_clear (ata_host_intr)
<idle>-0 0dnH. 3us : ata_qc_complete (ata_host_intr)
<idle>-0 0dnH. 4us : nommu_unmap_sg (ata_qc_complete)
<idle>-0 0dnH. 4us : ata_scsi_qc_complete (ata_qc_complete)
<idle>-0 0dnH. 4us : scsi_done (ata_scsi_qc_complete)
<idle>-0 0dnH. 4us : scsi_delete_timer (scsi_done)
<idle>-0 0dnH. 4us : del_timer (scsi_delete_timer)
<idle>-0 0dnH. 4us : lock_timer_base (del_timer)
<idle>-0 0dnH. 4us : _spin_lock_irqsave (lock_timer_base)
<idle>-0 0dnH. 4us : _spin_unlock_irqrestore (del_timer)
<idle>-0 0dnH. 4us : __scsi_done (scsi_done)
<idle>-0 0dnH. 5us : blk_complete_request (__scsi_done)
<idle>-0 0dnH. 5us : raise_softirq_irqoff (blk_complete_request)
<idle>-0 0dnH. 5us : __ata_qc_complete (ata_qc_complete)
<idle>-0 0dnH. 5us : ata_host_intr (nv_interrupt)
<idle>-0 0dnH. 5us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 5us!: ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 1726us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 1726us : nv_check_hotplug_ck804 (nv_interrupt)
<idle>-0 0dnH. 1726us : _spin_unlock_irqrestore (nv_interrupt)
<idle>-0 0dnH. 1727us : smp_apic_timer_interrupt (apic_timer_interrupt)
<idle>-0 0dnH. 1727us : exit_idle (smp_apic_timer_interrupt)
<idle>-0 0dnH. 1727us : in_lock_functions (add_preempt_count)
<idle>-0 0dnH. 1727us : smp_local_timer_interrupt (smp_apic_timer_interrupt)
<idle>-0 0dnH. 1727us : profile_tick (smp_local_timer_interrupt)
<idle>-0 0dnH. 1727us : profile_pc (profile_tick)
<idle>-0 0dnH. 1727us : in_lock_functions (profile_pc)
<idle>-0 0dnH. 1727us : profile_hit (profile_tick)
<idle>-0 0dnH. 1727us : update_process_times (smp_local_timer_interrupt)
<idle>-0 0dnH. 1727us : account_system_time (update_process_times)
<idle>-0 0dnH. 1728us : acct_update_integrals (account_system_time)
<idle>-0 0dnH. 1728us : run_local_timers (update_process_times)
<idle>-0 0dnH. 1728us : raise_softirq (run_local_timers)
<idle>-0 0dnH. 1728us : rcu_pending (update_process_times)
<idle>-0 0dnH. 1728us : __rcu_pending (rcu_pending)
<idle>-0 0dnH. 1728us : rcu_check_callbacks (update_process_times)
<idle>-0 0dnH. 1728us : idle_cpu (rcu_check_callbacks)
<idle>-0 0dnH. 1728us : __tasklet_schedule (rcu_check_callbacks)
<idle>-0 0dnH. 1728us : scheduler_tick (update_process_times)
<idle>-0 0dnH. 1728us : sched_clock (scheduler_tick)
<idle>-0 0dnH. 1729us : __lock_text_start (scheduler_tick)
<idle>-0 0dnH. 1729us : resched_task (scheduler_tick)
<idle>-0 0dnH. 1729us : rebalance_tick (scheduler_tick)
<idle>-0 0dnH. 1729us : run_posix_cpu_timers (update_process_times)
<idle>-0 0dnH. 1729us : irq_exit (smp_apic_timer_interrupt)
<idle>-0 0dnH. 1730us : do_IRQ (ret_from_intr)
<idle>-0 0dnH. 1730us : exit_idle (do_IRQ)
<idle>-0 0dnH. 1730us : in_lock_functions (add_preempt_count)
<idle>-0 0dnH. 1730us : __do_IRQ (do_IRQ)
<idle>-0 0dnH. 1730us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1730us : mask_and_ack_level_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1730us : handle_IRQ_event (__do_IRQ)
<idle>-0 0dnH. 1730us : nv_nic_irq (handle_IRQ_event)
<idle>-0 0dnH. 1731us : __lock_text_start (nv_nic_irq)
<idle>-0 0dnH. 1731us : nv_tx_done (nv_nic_irq)
<idle>-0 0dnH. 1731us : netpoll_trap (nv_tx_done)
<idle>-0 0dnH. 1731us : nommu_unmap_single (nv_nic_irq)
<idle>-0 0dnH. 1732us : eth_type_trans (nv_nic_irq)
<idle>-0 0dnH. 1732us : netif_rx (nv_nic_irq)
<idle>-0 0dnH. 1732us : nommu_unmap_single (nv_nic_irq)
<idle>-0 0dnH. 1733us : eth_type_trans (nv_nic_irq)
<idle>-0 0dnH. 1733us : netif_rx (nv_nic_irq)
<idle>-0 0dnH. 1733us : nommu_unmap_single (nv_nic_irq)
<idle>-0 0dnH. 1733us : eth_type_trans (nv_nic_irq)
<idle>-0 0dnH. 1734us : netif_rx (nv_nic_irq)
<idle>-0 0dnH. 1734us : nv_alloc_rx (nv_nic_irq)
<idle>-0 0dnH. 1734us : __alloc_skb (nv_alloc_rx)
<idle>-0 0dnH. 1734us : kmem_cache_alloc (__alloc_skb)
<idle>-0 0dnH. 1734us : __kmalloc (__alloc_skb)
<idle>-0 0dnH. 1735us : nommu_map_single (nv_alloc_rx)
<idle>-0 0dnH. 1735us : check_addr (nommu_map_single)
<idle>-0 0dnH. 1735us : __alloc_skb (nv_alloc_rx)
<idle>-0 0dnH. 1735us : kmem_cache_alloc (__alloc_skb)
<idle>-0 0dnH. 1735us : __kmalloc (__alloc_skb)
<idle>-0 0dnH. 1735us : nommu_map_single (nv_alloc_rx)
<idle>-0 0dnH. 1735us : check_addr (nommu_map_single)
<idle>-0 0dnH. 1735us : __alloc_skb (nv_alloc_rx)
<idle>-0 0dnH. 1736us : kmem_cache_alloc (__alloc_skb)
<idle>-0 0dnH. 1736us : __kmalloc (__alloc_skb)
<idle>-0 0dnH. 1736us : nommu_map_single (nv_alloc_rx)
<idle>-0 0dnH. 1736us : check_addr (nommu_map_single)
<idle>-0 0dnH. 1737us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1737us : note_interrupt (__do_IRQ)
<idle>-0 0dnH. 1737us : end_level_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1737us : irq_exit (do_IRQ)
<idle>-0 0dnH. 1737us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1738us : note_interrupt (__do_IRQ)
<idle>-0 0dnH. 1738us : end_level_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1738us : irq_exit (do_IRQ)
<idle>-0 0dns. 1738us : do_IRQ (ret_from_intr)
<idle>-0 0dns. 1738us : exit_idle (do_IRQ)
<idle>-0 0dns. 1738us : in_lock_functions (add_preempt_count)
<idle>-0 0dnH. 1738us : __do_IRQ (do_IRQ)
<idle>-0 0dnH. 1738us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1738us : ack_edge_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1739us : handle_IRQ_event (__do_IRQ)
<idle>-0 0dnH. 1739us : timer_interrupt (handle_IRQ_event)
<idle>-0 0dnH. 1739us : main_timer_handler (timer_interrupt)
<idle>-0 0dnH. 1739us : __lock_text_start (main_timer_handler)
<idle>-0 0dnH. 1739us+: __lock_text_start (main_timer_handler)
<idle>-0 0dnH. 1742us : pmtimer_mark_offset (main_timer_handler)
<idle>-0 0dnH. 1743us : handle_lost_ticks (main_timer_handler)
<idle>-0 0dnH. 1744us : printk (handle_lost_ticks)
<idle>-0 0dnH. 1744us : vprintk (printk)
<idle>-0 0dnH. 1744us : _spin_lock_irqsave (vprintk)
<idle>-0 0dnH. 1745us : vscnprintf (vprintk)
<idle>-0 0dnH. 1745us+: vsnprintf (vscnprintf)
<idle>-0 0dnH. 1747us : number (vsnprintf)
<idle>-0 0dnH. 1748us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1749us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1750us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1751us : emit_log_char (vprintk)
<idle>-0 0dnH. 1752us : emit_log_char (vprintk)
<idle>-0 0dnH. 1752us : _spin_unlock_irqrestore (vprintk)
<idle>-0 0dnH. 1752us : release_console_sem (vprintk)
<idle>-0 0dnH. 1752us : _spin_lock_irqsave (release_console_sem)
<idle>-0 0dnH. 1753us : _call_console_drivers (release_console_sem)
<idle>-0 0dnH. 1753us : _spin_lock_irqsave (release_console_sem)
<idle>-0 0dnH. 1753us : _spin_unlock_irqrestore (release_console_sem)
<idle>-0 0dnH. 1753us : __wake_up (release_console_sem)
<idle>-0 0dnH. 1753us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dnH. 1753us : __wake_up_common (__wake_up)
<idle>-0 0dnH. 1754us : default_wake_function (__wake_up_common)
<idle>-0 0dnH. 1754us : try_to_wake_up (default_wake_function)
<idle>-0 0dnH. 1754us : __lock_text_start (try_to_wake_up)
<idle>-0 0dnH. 1754us : idle_cpu (try_to_wake_up)
<idle>-0 0dnH. 1754us : activate_task (try_to_wake_up)
<idle>-0 0dnH. 1754us : sched_clock (activate_task)
<idle>-0 0dnH. 1755us : recalc_task_prio (activate_task)
<idle>-0 0dnH. 1755us : effective_prio (recalc_task_prio)
<idle>-0 0dnH. 1755us : activate_task <<...>-1774> (73 1)
<idle>-0 0dnH. 1755us : enqueue_task (activate_task)
<idle>-0 0dnH. 1755us : resched_task (try_to_wake_up)
<idle>-0 0dnH. 1756us : __trace_start_sched_wakeup (try_to_wake_up)
<idle>-0 0dnH. 1756us : __lock_text_start (__trace_start_sched_wakeup)
<idle>-0 0dnH. 1756us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dnH. 1756us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dnH. 1756us : __print_symbol (handle_lost_ticks)
<idle>-0 0dnH. 1757us : kallsyms_lookup (__print_symbol)
<idle>-0 0dnH. 1758us+: get_symbol_offset (kallsyms_lookup)
<idle>-0 0dnH. 1761us : kallsyms_expand_symbol (kallsyms_lookup)
<idle>-0 0dnH. 1762us : sprintf (__print_symbol)
<idle>-0 0dnH. 1763us : vsnprintf (sprintf)
<idle>-0 0dnH. 1763us : strnlen (vsnprintf)
<idle>-0 0dnH. 1764us : number (vsnprintf)
<idle>-0 0dnH. 1765us : number (vsnprintf)
<idle>-0 0dnH. 1765us : printk (__print_symbol)
<idle>-0 0dnH. 1765us : vprintk (printk)
<idle>-0 0dnH. 1765us : _spin_lock_irqsave (vprintk)
<idle>-0 0dnH. 1765us : vscnprintf (vprintk)
<idle>-0 0dnH. 1765us : vsnprintf (vscnprintf)
<idle>-0 0dnH. 1766us : strnlen (vsnprintf)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1766us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1767us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1768us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : emit_log_char (vprintk)
<idle>-0 0dnH. 1769us : _spin_unlock_irqrestore (vprintk)
<idle>-0 0dnH. 1769us : release_console_sem (vprintk)
<idle>-0 0dnH. 1769us : _spin_lock_irqsave (release_console_sem)
<idle>-0 0dnH. 1770us : _call_console_drivers (release_console_sem)
<idle>-0 0dnH. 1770us : _call_console_drivers (release_console_sem)
<idle>-0 0dnH. 1770us : _spin_lock_irqsave (release_console_sem)
<idle>-0 0dnH. 1770us : _spin_unlock_irqrestore (release_console_sem)
<idle>-0 0dnH. 1770us : __wake_up (release_console_sem)
<idle>-0 0dnH. 1770us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dnH. 1770us : __wake_up_common (__wake_up)
<idle>-0 0dnH. 1770us : default_wake_function (__wake_up_common)
<idle>-0 0dnH. 1771us : try_to_wake_up (default_wake_function)
<idle>-0 0dnH. 1771us : __lock_text_start (try_to_wake_up)
<idle>-0 0dnH. 1771us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dnH. 1771us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dnH. 1771us : do_timer (main_timer_handler)
<idle>-0 0dnH. 1771us : adjtime_adjustment (do_timer)
<idle>-0 0dnH. 1771us : adjtime_adjustment (do_timer)
<idle>-0 0dnH. 1772us : softlockup_tick (do_timer)
<idle>-0 0dnH. 1772us : smp_send_timer_broadcast_ipi (timer_interrupt)
<idle>-0 0dnH. 1772us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1772us : note_interrupt (__do_IRQ)
<idle>-0 0dnH. 1772us : end_edge_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1772us : irq_exit (do_IRQ)
<idle>-0 0dns. 1772us : do_IRQ (ret_from_intr)
<idle>-0 0dns. 1773us : exit_idle (do_IRQ)
<idle>-0 0dns. 1773us : in_lock_functions (add_preempt_count)
<idle>-0 0dnH. 1773us : __do_IRQ (do_IRQ)
<idle>-0 0dnH. 1773us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1773us : mask_and_ack_level_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1773us : handle_IRQ_event (__do_IRQ)
<idle>-0 0dnH. 1773us : nv_interrupt (handle_IRQ_event)
<idle>-0 0dnH. 1773us : _spin_lock_irqsave (nv_interrupt)
<idle>-0 0dnH. 1773us : ata_check_status (nv_interrupt)
<idle>-0 0dnH. 1774us : ata_host_intr (nv_interrupt)
<idle>-0 0dnH. 1774us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 1774us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 1774us : ata_bmdma_status (ata_host_intr)
<idle>-0 0dnH. 1774us : ata_bmdma_stop (ata_host_intr)
<idle>-0 0dnH. 1775us : ata_altstatus (ata_bmdma_stop)
<idle>-0 0dnH. 1775us : ata_altstatus (ata_host_intr)
<idle>-0 0dnH. 1775us : ata_check_status (ata_host_intr)
<idle>-0 0dnH. 1775us : ata_bmdma_irq_clear (ata_host_intr)
<idle>-0 0dnH. 1776us : ata_qc_complete (ata_host_intr)
<idle>-0 0dnH. 1776us : nommu_unmap_sg (ata_qc_complete)
<idle>-0 0dnH. 1776us : ata_scsi_qc_complete (ata_qc_complete)
<idle>-0 0dnH. 1776us : scsi_done (ata_scsi_qc_complete)
<idle>-0 0dnH. 1776us : scsi_delete_timer (scsi_done)
<idle>-0 0dnH. 1776us : del_timer (scsi_delete_timer)
<idle>-0 0dnH. 1777us : lock_timer_base (del_timer)
<idle>-0 0dnH. 1777us : _spin_lock_irqsave (lock_timer_base)
<idle>-0 0dnH. 1777us : _spin_unlock_irqrestore (del_timer)
<idle>-0 0dnH. 1777us : __scsi_done (scsi_done)
<idle>-0 0dnH. 1777us : blk_complete_request (__scsi_done)
<idle>-0 0dnH. 1777us : raise_softirq_irqoff (blk_complete_request)
<idle>-0 0dnH. 1777us : __ata_qc_complete (ata_qc_complete)
<idle>-0 0dnH. 1777us : nv_check_hotplug_ck804 (nv_interrupt)
<idle>-0 0dnH. 1778us : _spin_unlock_irqrestore (nv_interrupt)
<idle>-0 0dnH. 1778us : __lock_text_start (__do_IRQ)
<idle>-0 0dnH. 1778us : note_interrupt (__do_IRQ)
<idle>-0 0dnH. 1778us : end_level_ioapic_irq (__do_IRQ)
<idle>-0 0dnH. 1778us : irq_exit (do_IRQ)
<idle>-0 0dns. 1779us : run_timer_softirq (__do_softirq)
<idle>-0 0dns. 1779us : hrtimer_run_queues (run_timer_softirq)
<idle>-0 0dns. 1779us : ktime_get_real (hrtimer_run_queues)
<idle>-0 0dns. 1779us : getnstimeofday (ktime_get_real)
<idle>-0 0dns. 1779us : do_gettimeofday (getnstimeofday)
<idle>-0 0dns. 1780us : do_gettimeoffset_pm (do_gettimeofday)
<idle>-0 0dns. 1781us : _spin_lock_irq (hrtimer_run_queues)
<idle>-0 0dns. 1782us : ktime_get (hrtimer_run_queues)
<idle>-0 0dns. 1782us : ktime_get_ts (ktime_get)
<idle>-0 0dns. 1782us : getnstimeofday (ktime_get_ts)
<idle>-0 0dns. 1782us : do_gettimeofday (getnstimeofday)
<idle>-0 0dns. 1782us : do_gettimeoffset_pm (do_gettimeofday)
<idle>-0 0dns. 1784us : set_normalized_timespec (ktime_get_ts)
<idle>-0 0dns. 1784us : _spin_lock_irq (hrtimer_run_queues)
<idle>-0 0dns. 1784us : _spin_lock_irq (run_timer_softirq)
<idle>-0 0dns. 1785us : i8042_timer_func (run_timer_softirq)
<idle>-0 0dns. 1785us : i8042_interrupt (i8042_timer_func)
<idle>-0 0dns. 1785us : mod_timer (i8042_interrupt)
<idle>-0 0dns. 1785us : __mod_timer (mod_timer)
<idle>-0 0dns. 1785us : lock_timer_base (__mod_timer)
<idle>-0 0dns. 1786us : _spin_lock_irqsave (lock_timer_base)
<idle>-0 0dns. 1786us : internal_add_timer (__mod_timer)
<idle>-0 0dns. 1786us : _spin_unlock_irqrestore (__mod_timer)
<idle>-0 0dns. 1786us : _spin_lock_irqsave (i8042_interrupt)
<idle>-0 0dns. 1788us : _spin_unlock_irqrestore (i8042_interrupt)
<idle>-0 0dns. 1788us : _spin_lock_irq (run_timer_softirq)
<idle>-0 0dns. 1788us : net_rx_action (__do_softirq)
<idle>-0 0dns. 1788us : process_backlog (net_rx_action)
<idle>-0 0dns. 1789us : netif_receive_skb (process_backlog)
<idle>-0 0dns. 1789us : vlan_skb_recv (netif_receive_skb)
<idle>-0 0dns. 1789us : __find_vlan_dev (vlan_skb_recv)
<idle>-0 0dns. 1789us : __vlan_find_group (__find_vlan_dev)
<idle>-0 0dns. 1790us : memmove (vlan_skb_recv)
<idle>-0 0dns. 1790us : netif_rx (vlan_skb_recv)
<idle>-0 0dns. 1790us : netif_receive_skb (process_backlog)
<idle>-0 0dns. 1791us : vlan_skb_recv (netif_receive_skb)
<idle>-0 0dns. 1791us : __find_vlan_dev (vlan_skb_recv)
<idle>-0 0dns. 1791us : __vlan_find_group (__find_vlan_dev)
<idle>-0 0dns. 1791us : memmove (vlan_skb_recv)
<idle>-0 0dns. 1792us : netif_rx (vlan_skb_recv)
<idle>-0 0dns. 1792us : netif_receive_skb (process_backlog)
<idle>-0 0dns. 1792us : vlan_skb_recv (netif_receive_skb)
<idle>-0 0dns. 1792us : __find_vlan_dev (vlan_skb_recv)
<idle>-0 0dns. 1793us : __vlan_find_group (__find_vlan_dev)
<idle>-0 0dns. 1793us : memmove (vlan_skb_recv)
<idle>-0 0dns. 1793us : netif_rx (vlan_skb_recv)
<idle>-0 0dns. 1793us : netif_receive_skb (process_backlog)
<idle>-0 0dns. 1794us : ip_rcv (netif_receive_skb)
<idle>-0 0dns. 1794us : ip_route_input (ip_rcv)
<idle>-0 0dns. 1794us : rt_hash_code (ip_route_input)
<idle>-0 0dns. 1794us : ip_local_deliver (ip_rcv)
<idle>-0 0dns. 1795us : udp_rcv (ip_local_deliver)
<idle>-0 0dns. 1795us : _read_lock (udp_rcv)
<idle>-0 0dns. 1795us : ip_mc_sf_allow (udp_rcv)
<idle>-0 0dns. 1795us : udp_queue_rcv_skb (udp_rcv)
<idle>-0 0dns. 1796us : dummy_socket_sock_rcv_skb (udp_queue_rcv_skb)
<idle>-0 0dns. 1796us : skb_queue_tail (udp_queue_rcv_skb)
<idle>-0 0dns. 1796us : _spin_lock_irqsave (skb_queue_tail)
<idle>-0 0dns. 1796us : _spin_unlock_irqrestore (skb_queue_tail)
<idle>-0 0dns. 1796us : sock_def_readable (udp_queue_rcv_skb)
<idle>-0 0dns. 1796us : _read_lock (sock_def_readable)
<idle>-0 0dns. 1797us : __wake_up (sock_def_readable)
<idle>-0 0dns. 1797us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1797us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1797us : default_wake_function (__wake_up_common)
<idle>-0 0dns. 1797us : try_to_wake_up (default_wake_function)
<idle>-0 0dns. 1797us : __lock_text_start (try_to_wake_up)
<idle>-0 0dns. 1798us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dns. 1798us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1798us : netif_receive_skb (process_backlog)
<idle>-0 0dns. 1799us : ip_rcv (netif_receive_skb)
<idle>-0 0dns. 1799us : ip_route_input (ip_rcv)
<idle>-0 0dns. 1799us : rt_hash_code (ip_route_input)
<idle>-0 0dns. 1799us : ip_local_deliver (ip_rcv)
<idle>-0 0dns. 1799us : udp_rcv (ip_local_deliver)
<idle>-0 0dns. 1800us : _read_lock (udp_rcv)
<idle>-0 0dns. 1800us : ip_mc_sf_allow (udp_rcv)
<idle>-0 0dns. 1800us : udp_queue_rcv_skb (udp_rcv)
<idle>-0 0dns. 1800us : dummy_socket_sock_rcv_skb (udp_queue_rcv_skb)
<idle>-0 0dns. 1800us : skb_queue_tail (udp_queue_rcv_skb)
<idle>-0 0dns. 1800us : _spin_lock_irqsave (skb_queue_tail)
<idle>-0 0dns. 1801us : _spin_unlock_irqrestore (skb_queue_tail)
<idle>-0 0dns. 1801us : sock_def_readable (udp_queue_rcv_skb)
<idle>-0 0dns. 1801us : _read_lock (sock_def_readable)
<idle>-0 0dns. 1801us : __wake_up (sock_def_readable)
<idle>-0 0dns. 1801us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1801us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1801us : default_wake_function (__wake_up_common)
<idle>-0 0dns. 1802us : try_to_wake_up (default_wake_function)
<idle>-0 0dns. 1802us : __lock_text_start (try_to_wake_up)
<idle>-0 0dns. 1802us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dns. 1802us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1802us : netif_receive_skb (process_backlog)
<idle>-0 0dns. 1803us : ip_rcv (netif_receive_skb)
<idle>-0 0dns. 1803us : ip_route_input (ip_rcv)
<idle>-0 0dns. 1803us : rt_hash_code (ip_route_input)
<idle>-0 0dns. 1803us : ip_local_deliver (ip_rcv)
<idle>-0 0dns. 1803us : udp_rcv (ip_local_deliver)
<idle>-0 0dns. 1803us : _read_lock (udp_rcv)
<idle>-0 0dns. 1804us : ip_mc_sf_allow (udp_rcv)
<idle>-0 0dns. 1804us : udp_queue_rcv_skb (udp_rcv)
<idle>-0 0dns. 1804us : dummy_socket_sock_rcv_skb (udp_queue_rcv_skb)
<idle>-0 0dns. 1804us : skb_queue_tail (udp_queue_rcv_skb)
<idle>-0 0dns. 1804us : _spin_lock_irqsave (skb_queue_tail)
<idle>-0 0dns. 1804us : _spin_unlock_irqrestore (skb_queue_tail)
<idle>-0 0dns. 1805us : sock_def_readable (udp_queue_rcv_skb)
<idle>-0 0dns. 1805us : _read_lock (sock_def_readable)
<idle>-0 0dns. 1805us : __wake_up (sock_def_readable)
<idle>-0 0dns. 1805us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1805us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1805us : default_wake_function (__wake_up_common)
<idle>-0 0dns. 1805us : try_to_wake_up (default_wake_function)
<idle>-0 0dns. 1805us : __lock_text_start (try_to_wake_up)
<idle>-0 0dns. 1806us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dns. 1806us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1806us : blk_done_softirq (__do_softirq)
<idle>-0 0dns. 1806us : scsi_softirq_done (blk_done_softirq)
<idle>-0 0dns. 1807us : scsi_decide_disposition (scsi_softirq_done)
<idle>-0 0dns. 1807us : scsi_log_completion (scsi_softirq_done)
<idle>-0 0dns. 1807us : scsi_finish_command (scsi_softirq_done)
<idle>-0 0dns. 1807us : scsi_device_unbusy (scsi_finish_command)
<idle>-0 0dns. 1807us : _spin_lock_irqsave (scsi_device_unbusy)
<idle>-0 0dns. 1807us : __lock_text_start (scsi_device_unbusy)
<idle>-0 0dns. 1807us : _spin_unlock_irqrestore (scsi_device_unbusy)
<idle>-0 0dns. 1808us : sd_rw_intr (scsi_finish_command)
<idle>-0 0dns. 1808us : scsi_io_completion (sd_rw_intr)
<idle>-0 0dns. 1808us : scsi_free_sgtable (scsi_io_completion)
<idle>-0 0dns. 1808us : mempool_free (scsi_free_sgtable)
<idle>-0 0dns. 1808us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1808us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1809us : scsi_end_request (scsi_io_completion)
<idle>-0 0dns. 1809us : end_that_request_chunk (scsi_end_request)
<idle>-0 0dns. 1809us : __end_that_request_first (end_that_request_chunk)
<idle>-0 0dns. 1809us : bio_endio (__end_that_request_first)
<idle>-0 0dns. 1809us : raid1_end_read_request (bio_endio)
<idle>-0 0dns. 1810us : raid_end_bio_io (raid1_end_read_request)
<idle>-0 0dns. 1810us : bio_endio (raid_end_bio_io)
<idle>-0 0dns. 1810us : clone_endio (bio_endio)
<idle>-0 0dns. 1810us : mempool_free (clone_endio)
<idle>-0 0dns. 1810us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1810us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1810us : dec_pending (clone_endio)
<idle>-0 0dns. 1811us : disk_round_stats (dec_pending)
<idle>-0 0dns. 1811us : __wake_up (dec_pending)
<idle>-0 0dns. 1811us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1811us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1811us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1811us : bio_endio (dec_pending)
<idle>-0 0dns. 1812us : mpage_end_io_read (bio_endio)
<idle>-0 0dns. 1812us : unlock_page (mpage_end_io_read)
<idle>-0 0dns. 1812us : page_waitqueue (unlock_page)
<idle>-0 0dns. 1812us : __wake_up_bit (unlock_page)
<idle>-0 0dns. 1812us : unlock_page (mpage_end_io_read)
<idle>-0 0dns. 1812us : page_waitqueue (unlock_page)
<idle>-0 0dns. 1813us : __wake_up_bit (unlock_page)
<idle>-0 0dns. 1813us : __wake_up (__wake_up_bit)
<idle>-0 0dns. 1813us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1813us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1813us : wake_bit_function (__wake_up_common)
<idle>-0 0dns. 1813us : autoremove_wake_function (wake_bit_function)
<idle>-0 0dns. 1813us : default_wake_function (autoremove_wake_function)
<idle>-0 0dns. 1814us : try_to_wake_up (default_wake_function)
<idle>-0 0dns. 1814us : __lock_text_start (try_to_wake_up)
<idle>-0 0dns. 1814us : idle_cpu (try_to_wake_up)
<idle>-0 0dns. 1814us : activate_task (try_to_wake_up)
<idle>-0 0dns. 1814us : sched_clock (activate_task)
<idle>-0 0dns. 1814us : recalc_task_prio (activate_task)
<idle>-0 0dns. 1815us : effective_prio (recalc_task_prio)
<idle>-0 0dns. 1815us : activate_task <<...>-3524> (76 2)
<idle>-0 0dns. 1815us : enqueue_task (activate_task)
<idle>-0 0dns. 1815us : resched_task (try_to_wake_up)
<idle>-0 0dns. 1815us : __trace_start_sched_wakeup (try_to_wake_up)
<idle>-0 0dns. 1816us : __lock_text_start (__trace_start_sched_wakeup)
<idle>-0 0dns. 1816us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dns. 1816us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1816us : bio_put (mpage_end_io_read)
<idle>-0 0dns. 1816us : bio_fs_destructor (bio_put)
<idle>-0 0dns. 1816us : bio_free (bio_fs_destructor)
<idle>-0 0dns. 1817us : mempool_free (bio_free)
<idle>-0 0dns. 1817us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1817us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1817us : mempool_free (bio_free)
<idle>-0 0dns. 1817us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1818us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1818us : mempool_free (dec_pending)
<idle>-0 0dns. 1818us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1818us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1818us : bio_put (clone_endio)
<idle>-0 0dns. 1819us : bio_fs_destructor (bio_put)
<idle>-0 0dns. 1819us : bio_free (bio_fs_destructor)
<idle>-0 0dns. 1819us : mempool_free (bio_free)
<idle>-0 0dns. 1819us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1819us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1819us : mempool_free (bio_free)
<idle>-0 0dns. 1820us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1820us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1820us : allow_barrier (raid_end_bio_io)
<idle>-0 0dns. 1820us : _spin_lock_irqsave (allow_barrier)
<idle>-0 0dns. 1820us : _spin_unlock_irqrestore (allow_barrier)
<idle>-0 0dns. 1821us : __wake_up (allow_barrier)
<idle>-0 0dns. 1821us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1821us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1821us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1821us : bio_put (raid_end_bio_io)
<idle>-0 0dns. 1821us : bio_fs_destructor (bio_put)
<idle>-0 0dns. 1822us : bio_free (bio_fs_destructor)
<idle>-0 0dns. 1822us : mempool_free (bio_free)
<idle>-0 0dns. 1822us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1822us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1822us : mempool_free (bio_free)
<idle>-0 0dns. 1822us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1823us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1823us : mempool_free (raid_end_bio_io)
<idle>-0 0dns. 1823us : r1bio_pool_free (mempool_free)
<idle>-0 0dns. 1823us : kfree (r1bio_pool_free)
<idle>-0 0dns. 1824us : add_disk_randomness (scsi_end_request)
<idle>-0 0dns. 1824us : add_timer_randomness (add_disk_randomness)
<idle>-0 0dns. 1824us : _spin_lock_irqsave (scsi_end_request)
<idle>-0 0dns. 1824us : end_that_request_last (scsi_end_request)
<idle>-0 0dns. 1824us : disk_round_stats (end_that_request_last)
<idle>-0 0dns. 1824us : __blk_put_request (end_that_request_last)
<idle>-0 0dns. 1825us : elv_completed_request (__blk_put_request)
<idle>-0 0dns. 1825us : cfq_completed_request (elv_completed_request)
<idle>-0 0dns. 1825us : elv_put_request (__blk_put_request)
<idle>-0 0dns. 1825us : cfq_put_request (elv_put_request)
<idle>-0 0dns. 1826us : put_io_context (cfq_put_request)
<idle>-0 0dns. 1826us : mempool_free (cfq_put_request)
<idle>-0 0dns. 1826us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1826us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1826us : cfq_put_queue (cfq_put_request)
<idle>-0 0dns. 1827us : mempool_free (__blk_put_request)
<idle>-0 0dns. 1827us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1827us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1827us : freed_request (__blk_put_request)
<idle>-0 0dns. 1827us : __freed_request (freed_request)
<idle>-0 0dns. 1827us : clear_queue_congested (__freed_request)
<idle>-0 0dns. 1828us : _spin_unlock_irqrestore (scsi_end_request)
<idle>-0 0dns. 1828us : scsi_next_command (scsi_end_request)
<idle>-0 0dns. 1828us : get_device (scsi_next_command)
<idle>-0 0dns. 1828us : kobject_get (get_device)
<idle>-0 0dns. 1828us : kref_get (kobject_get)
<idle>-0 0dns. 1829us : scsi_put_command (scsi_next_command)
<idle>-0 0dns. 1829us : _spin_lock_irqsave (scsi_put_command)
<idle>-0 0dns. 1829us : __lock_text_start (scsi_put_command)
<idle>-0 0dns. 1829us : _spin_unlock_irqrestore (scsi_put_command)
<idle>-0 0dns. 1829us : kmem_cache_free (scsi_put_command)
<idle>-0 0dns. 1829us : put_device (scsi_put_command)
<idle>-0 0dns. 1830us : kobject_put (put_device)
<idle>-0 0dns. 1830us : kref_put (kobject_put)
<idle>-0 0dns. 1830us : scsi_run_queue (scsi_next_command)
<idle>-0 0dns. 1830us : _spin_lock_irqsave (scsi_run_queue)
<idle>-0 0dns. 1830us : _spin_unlock_irqrestore (scsi_run_queue)
<idle>-0 0dns. 1830us : blk_run_queue (scsi_run_queue)
<idle>-0 0dns. 1831us : _spin_lock_irqsave (blk_run_queue)
<idle>-0 0dns. 1831us : blk_remove_plug (blk_run_queue)
<idle>-0 0dns. 1831us : elv_queue_empty (blk_run_queue)
<idle>-0 0dns. 1831us : cfq_queue_empty (elv_queue_empty)
<idle>-0 0dns. 1831us : _spin_unlock_irqrestore (blk_run_queue)
<idle>-0 0dns. 1831us : put_device (scsi_next_command)
<idle>-0 0dns. 1831us : kobject_put (put_device)
<idle>-0 0dns. 1831us : kref_put (kobject_put)
<idle>-0 0dns. 1832us : scsi_softirq_done (blk_done_softirq)
<idle>-0 0dns. 1832us : scsi_decide_disposition (scsi_softirq_done)
<idle>-0 0dns. 1832us : scsi_log_completion (scsi_softirq_done)
<idle>-0 0dns. 1832us : scsi_finish_command (scsi_softirq_done)
<idle>-0 0dns. 1832us : scsi_device_unbusy (scsi_finish_command)
<idle>-0 0dns. 1833us : _spin_lock_irqsave (scsi_device_unbusy)
<idle>-0 0dns. 1833us : __lock_text_start (scsi_device_unbusy)
<idle>-0 0dns. 1833us : _spin_unlock_irqrestore (scsi_device_unbusy)
<idle>-0 0dns. 1833us : sd_rw_intr (scsi_finish_command)
<idle>-0 0dns. 1833us : scsi_io_completion (sd_rw_intr)
<idle>-0 0dns. 1833us : scsi_free_sgtable (scsi_io_completion)
<idle>-0 0dns. 1833us : mempool_free (scsi_free_sgtable)
<idle>-0 0dns. 1833us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1834us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1834us : scsi_end_request (scsi_io_completion)
<idle>-0 0dns. 1834us : end_that_request_chunk (scsi_end_request)
<idle>-0 0dns. 1834us : __end_that_request_first (end_that_request_chunk)
<idle>-0 0dns. 1834us : bio_endio (__end_that_request_first)
<idle>-0 0dns. 1834us : raid1_end_read_request (bio_endio)
<idle>-0 0dns. 1835us : raid_end_bio_io (raid1_end_read_request)
<idle>-0 0dns. 1835us : bio_endio (raid_end_bio_io)
<idle>-0 0dns. 1835us : clone_endio (bio_endio)
<idle>-0 0dns. 1835us : mempool_free (clone_endio)
<idle>-0 0dns. 1835us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1835us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1836us : dec_pending (clone_endio)
<idle>-0 0dns. 1836us : disk_round_stats (dec_pending)
<idle>-0 0dns. 1836us : __wake_up (dec_pending)
<idle>-0 0dns. 1836us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1836us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1837us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1837us : bio_endio (dec_pending)
<idle>-0 0dns. 1837us : end_bio_bh_io_sync (bio_endio)
<idle>-0 0dns. 1837us : end_buffer_read_sync (end_bio_bh_io_sync)
<idle>-0 0dns. 1837us : unlock_buffer (end_buffer_read_sync)
<idle>-0 0dns. 1837us : wake_up_bit (unlock_buffer)
<idle>-0 0dns. 1837us : bit_waitqueue (wake_up_bit)
<idle>-0 0dns. 1837us : __wake_up_bit (wake_up_bit)
<idle>-0 0dns. 1838us : __wake_up (__wake_up_bit)
<idle>-0 0dns. 1838us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1838us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1838us : wake_bit_function (__wake_up_common)
<idle>-0 0dns. 1838us : autoremove_wake_function (wake_bit_function)
<idle>-0 0dns. 1838us : default_wake_function (autoremove_wake_function)
<idle>-0 0dns. 1838us : try_to_wake_up (default_wake_function)
<idle>-0 0dns. 1839us : __lock_text_start (try_to_wake_up)
<idle>-0 0dns. 1839us : idle_cpu (try_to_wake_up)
<idle>-0 0dns. 1839us : activate_task (try_to_wake_up)
<idle>-0 0dns. 1839us : sched_clock (activate_task)
<idle>-0 0dns. 1839us : recalc_task_prio (activate_task)
<idle>-0 0dns. 1840us : effective_prio (recalc_task_prio)
<idle>-0 0dns. 1840us : activate_task <<...>-3525> (76 3)
<idle>-0 0dns. 1840us : enqueue_task (activate_task)
<idle>-0 0dns. 1840us : resched_task (try_to_wake_up)
<idle>-0 0dns. 1840us : __trace_start_sched_wakeup (try_to_wake_up)
<idle>-0 0dns. 1840us : __lock_text_start (__trace_start_sched_wakeup)
<idle>-0 0dns. 1840us : _spin_unlock_irqrestore (try_to_wake_up)
<idle>-0 0dns. 1841us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1841us : bio_put (end_bio_bh_io_sync)
<idle>-0 0dns. 1841us : bio_fs_destructor (bio_put)
<idle>-0 0dns. 1841us : bio_free (bio_fs_destructor)
<idle>-0 0dns. 1841us : mempool_free (bio_free)
<idle>-0 0dns. 1842us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1842us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1842us : mempool_free (bio_free)
<idle>-0 0dns. 1842us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1842us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1842us : mempool_free (dec_pending)
<idle>-0 0dns. 1842us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1843us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1843us : bio_put (clone_endio)
<idle>-0 0dns. 1843us : bio_fs_destructor (bio_put)
<idle>-0 0dns. 1843us : bio_free (bio_fs_destructor)
<idle>-0 0dns. 1843us : mempool_free (bio_free)
<idle>-0 0dns. 1843us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1843us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1844us : mempool_free (bio_free)
<idle>-0 0dns. 1844us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1844us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1844us : allow_barrier (raid_end_bio_io)
<idle>-0 0dns. 1844us : _spin_lock_irqsave (allow_barrier)
<idle>-0 0dns. 1844us : _spin_unlock_irqrestore (allow_barrier)
<idle>-0 0dns. 1844us : __wake_up (allow_barrier)
<idle>-0 0dns. 1844us : _spin_lock_irqsave (__wake_up)
<idle>-0 0dns. 1845us : __wake_up_common (__wake_up)
<idle>-0 0dns. 1845us : _spin_unlock_irqrestore (__wake_up)
<idle>-0 0dns. 1845us : bio_put (raid_end_bio_io)
<idle>-0 0dns. 1845us : bio_fs_destructor (bio_put)
<idle>-0 0dns. 1845us : bio_free (bio_fs_destructor)
<idle>-0 0dns. 1846us : mempool_free (bio_free)
<idle>-0 0dns. 1846us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1846us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1846us : mempool_free (bio_free)
<idle>-0 0dns. 1846us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1846us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1847us : mempool_free (raid_end_bio_io)
<idle>-0 0dns. 1847us : r1bio_pool_free (mempool_free)
<idle>-0 0dns. 1847us : kfree (r1bio_pool_free)
<idle>-0 0dns. 1847us : add_disk_randomness (scsi_end_request)
<idle>-0 0dns. 1847us : add_timer_randomness (add_disk_randomness)
<idle>-0 0dns. 1848us : _spin_lock_irqsave (scsi_end_request)
<idle>-0 0dns. 1848us : end_that_request_last (scsi_end_request)
<idle>-0 0dns. 1848us : disk_round_stats (end_that_request_last)
<idle>-0 0dns. 1848us : __blk_put_request (end_that_request_last)
<idle>-0 0dns. 1848us : elv_completed_request (__blk_put_request)
<idle>-0 0dns. 1849us : cfq_completed_request (elv_completed_request)
<idle>-0 0dns. 1849us : elv_put_request (__blk_put_request)
<idle>-0 0dns. 1849us : cfq_put_request (elv_put_request)
<idle>-0 0dns. 1849us : put_io_context (cfq_put_request)
<idle>-0 0dns. 1850us : mempool_free (cfq_put_request)
<idle>-0 0dns. 1850us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1850us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1850us : cfq_put_queue (cfq_put_request)
<idle>-0 0dns. 1850us : mempool_free (__blk_put_request)
<idle>-0 0dns. 1850us : mempool_free_slab (mempool_free)
<idle>-0 0dns. 1851us : kmem_cache_free (mempool_free_slab)
<idle>-0 0dns. 1851us : freed_request (__blk_put_request)
<idle>-0 0dns. 1851us : __freed_request (freed_request)
<idle>-0 0dns. 1851us : clear_queue_congested (__freed_request)
<idle>-0 0dns. 1851us : _spin_unlock_irqrestore (scsi_end_request)
<idle>-0 0dns. 1852us : scsi_next_command (scsi_end_request)
<idle>-0 0dns. 1852us : get_device (scsi_next_command)
<idle>-0 0dns. 1852us : kobject_get (get_device)
<idle>-0 0dns. 1852us : kref_get (kobject_get)
<idle>-0 0dns. 1852us : scsi_put_command (scsi_next_command)
<idle>-0 0dns. 1852us : _spin_lock_irqsave (scsi_put_command)
<idle>-0 0dns. 1853us : __lock_text_start (scsi_put_command)
<idle>-0 0dns. 1853us : _spin_unlock_irqrestore (scsi_put_command)
<idle>-0 0dns. 1853us : kmem_cache_free (scsi_put_command)
<idle>-0 0dns. 1853us : put_device (scsi_put_command)
<idle>-0 0dns. 1853us : kobject_put (put_device)
<idle>-0 0dns. 1853us : kref_put (kobject_put)
<idle>-0 0dns. 1854us : scsi_run_queue (scsi_next_command)
<idle>-0 0dns. 1854us : _spin_lock_irqsave (scsi_run_queue)
<idle>-0 0dns. 1854us : _spin_unlock_irqrestore (scsi_run_queue)
<idle>-0 0dns. 1854us : blk_run_queue (scsi_run_queue)
<idle>-0 0dns. 1854us : _spin_lock_irqsave (blk_run_queue)
<idle>-0 0dns. 1854us : blk_remove_plug (blk_run_queue)
<idle>-0 0dns. 1855us : elv_queue_empty (blk_run_queue)
<idle>-0 0dns. 1855us : cfq_queue_empty (elv_queue_empty)
<idle>-0 0dns. 1855us : _spin_unlock_irqrestore (blk_run_queue)
<idle>-0 0dns. 1855us : put_device (scsi_next_command)
<idle>-0 0dns. 1855us : kobject_put (put_device)
<idle>-0 0dns. 1855us : kref_put (kobject_put)
<idle>-0 0dns. 1856us : tasklet_action (__do_softirq)
<idle>-0 0dns. 1856us : rcu_process_callbacks (tasklet_action)
<idle>-0 0dns. 1856us : __rcu_process_callbacks (rcu_process_callbacks)
<idle>-0 0dns. 1856us : __lock_text_start (__rcu_process_callbacks)
<idle>-0 0dns. 1856us : rcu_start_batch (__rcu_process_callbacks)
<idle>-0 0dns. 1857us : __rcu_process_callbacks (rcu_process_callbacks)
<idle>-0 0dn.. 1857us : __exit_idle (cpu_idle)
<idle>-0 0dn.. 1857us : notifier_call_chain (__exit_idle)
<idle>-0 0dn.. 1857us : schedule (cpu_idle)
<idle>-0 0dn.. 1858us : profile_hit (schedule)
<idle>-0 0dn.. 1858us : sched_clock (schedule)
<idle>-0 0dn.. 1858us : _spin_lock_irq (schedule)
<idle>-0 0dn.. 1858us : recalc_task_prio (schedule)
<idle>-0 0dn.. 1859us : effective_prio (recalc_task_prio)
<idle>-0 0dn.. 1859us : requeue_task (schedule)
<idle>-0 0d... 1859us : __kprobes_text_start (thread_return)
<...>-3032 0d... 1860us : thread_return <<idle>-0> (8c 69)
<...>-3032 0d... 1860us : trace_stop_sched_switched (thread_return)
<...>-3032 0d... 1860us : __lock_text_start (trace_stop_sched_switched)
<...>-3032 0d... 1860us : trace_stop_sched_switched <<...>-3032> (69 0)
<...>-3032 0d... 1861us : thread_return (thread_return)

vim:ft=help
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Next message: Srivatsa Vaddagiri: "Re: cpu_exclusive feature of cpuset broken?"
Previous message: Jes Sorensen: "[patch] mspec - special memory driver and do_no_pfn handler"
In reply to: Alan Cox: "Re: libata/sata_nv latency on NVIDIA CK804 [was Re: AMD64 X2 lostticks on PM timer]"
Next in thread: Andi Kleen: "Re: libata/sata_nv latency on NVIDIA CK804 [was Re: AMD64 X2 lost ticks on PM timer]"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]