BeagleBone Xenomai Latency

Asked by 3 months ago
(Starting a new thread) OK, I tested a variety of kernels. Simply enabling the ipipe trace options on the otherwise unchanged kernel configuration I'm using resulted in a system that was *EXTREMELY* slow and unresponsive, even before I enabled the iPipe trace. After waiting the better part of a day for a GUI application to launch, I gave up on this kernel and tested one with the recommended performance options: Already in the BeagleBone Xenomai kernels I've been building: Updated to desired setting in dbg_opt kernel: Recommended but not selected (causes linking errors apparently due to the kernel size being too large for some of the limited reach thumb2 jump/branch instructions): This resulted in a much more usable kernel and the resulting frozen details are attached, along with the kernel configuration for reference. Let me know if you spot anything, or if I can provide any more details. I also have a couple frozen dumps from the debugging kernel with really awful performance, if it's of interest. OVERALL RESULTS: Adding the recommended options dramatically helped with latency when iPipe trace was enabled, but not so much for the normal kernel. I did see typical and best case latency drop significantly (by about 25%) with the recommended options, but worst-case latency for both kernels remained around 50 uS. This is still a substantial improvement over the 80-90 uS worst-case latencies I was getting with the first Xenomai kernels for the BeagleBone (prior to the official release of a supported iPipe patch). +----- Hard IRQs ('|': locked) |+-- Xenomai ||+- Linux ('*': domain stalled, '+': current, '#': current+stalled) ||| +---------- Delay flag ('+': > 1 us, '!': > 10 us) ||| | +- NMI noise ('N') ||| | | Type User Val. Time Delay Function (Parent) : #func -1804 1.000 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -1803 0.720 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -1802 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1801+ 1.480 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -1800 0.680 rcu_bh_qs+0x10 (__do_softirq+0x168) :| +begin 0x80000001 -1799 0.760 rcu_bh_qs+0x2c (__do_softirq+0x168) :| #end 0x80000001 -1798 1.000 rcu_bh_qs+0x4c (__do_softirq+0x168) : #func -1797 0.680 ipipe_unstall_root+0x10 (rcu_bh_qs+0x9c) :| #begin 0x80000000 -1797+ 1.040 ipipe_unstall_root+0x2c (rcu_bh_qs+0x9c) :| #func -1796 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1795 0.960 ipipe_unstall_root+0x64 (rcu_bh_qs+0x9c) :| +begin 0x80000001 -1794+ 1.040 __do_softirq+0x18c (irq_exit+0x54) :| #end 0x80000001 -1793 0.720 __do_softirq+0x1ac (irq_exit+0x54) : #func -1792+ 1.320 __local_bh_enable+0x10 (__do_softirq+0x1d8) : #func -1791+ 1.120 ipipe_root_only+0x10 (__local_bh_enable+0x9c) : #func -1790+ 1.360 idle_cpu+0x10 (irq_exit+0x5c) : #func -1789 0.960 rcu_irq_exit+0x10 (irq_exit+0x98) :| #begin 0x80000001 -1788 0.800 rcu_irq_exit+0x2c (irq_exit+0x98) :| #end 0x80000001 -1787+ 2.000 rcu_irq_exit+0x4c (irq_exit+0x98) :| #begin 0x80000000 -1785+ 1.240 __ipipe_do_sync_stage+0x22c (__ipipe_do_sync_pipeline+0x9c) :| +end 0x00000053 -1784 0.600 __ipipe_grab_irq+0x94 (omap3_intc_handle_irq+0x70) :| +func -1783+ 1.080 __ipipe_exit_irq+0x10 (__ipipe_grab_irq+0x9c) :| +func -1782+ 1.120 __ipipe_check_root_interruptible+0x10 (__irq_svc+0x5c) :| +func -1781 0.640 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_fast_svc_irq_exit+0x4) :| +end 0x90000000 -1780+ 1.200 __ipipe_fast_svc_irq_exit+0x18 (ipipe_unstall_root+0x68) : +func -1779 0.640 mempool_alloc+0x14 (get_request+0x2ec) : +func -1778 1.000 ipipe_root_only+0x10 (mempool_alloc+0x2c) : +func -1777+ 1.120 _cond_resched+0x10 (mempool_alloc+0x30) : +func -1776 0.720 mempool_alloc_slab+0x10 (mempool_alloc+0x64) : +func -1775 0.800 kmem_cache_alloc+0x14 (mempool_alloc_slab+0x24) :| +begin 0x80000001 -1775+ 1.040 kmem_cache_alloc+0x58 (mempool_alloc_slab+0x24) :| #end 0x80000001 -1774+ 2.400 kmem_cache_alloc+0x78 (mempool_alloc_slab+0x24) : #func -1771+ 1.400 ipipe_unstall_root+0x10 (kmem_cache_alloc+0xd8) :| #begin 0x80000000 -1770 0.760 ipipe_unstall_root+0x2c (kmem_cache_alloc+0xd8) :| #func -1769 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1768+ 1.680 ipipe_unstall_root+0x64 (kmem_cache_alloc+0xd8) : +func -1766+ 4.480 blk_rq_init+0x10 (get_request+0x300) : +func -1762+ 1.280 elv_set_request+0x10 (get_request+0x36c) : +func -1761+ 1.320 cfq_set_request+0x14 (elv_set_request+0x2c) : +func -1759 0.720 ipipe_root_only+0x10 (cfq_set_request+0x5c) : +func -1759 0.680 _cond_resched+0x10 (cfq_set_request+0x60) : +func -1758 0.680 _raw_spin_lock_irq+0x10 (cfq_set_request+0x68) :| +begin 0x80000001 -1757 0.800 _raw_spin_lock_irq+0x30 (cfq_set_request+0x68) :| #end 0x80000001 -1756+ 4.280 _raw_spin_lock_irq+0x50 (cfq_set_request+0x68) : #func -1752 0.720 _raw_spin_unlock_irq+0x10 (cfq_set_request+0x204) : #func -1751 1.000 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -1750 0.840 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -1750 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1749 1.000 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -1748+ 2.160 get_io_context+0x10 (get_request+0x388) : +func -1746+ 1.840 init_request_from_bio+0x10 (blk_queue_bio+0x1d0) : +func -1744+ 1.320 blk_rq_bio_prep+0x10 (init_request_from_bio+0x6c) : +func -1742+ 1.240 blk_recount_segments+0x10 (bio_phys_segments+0x20) : +func -1741+ 3.040 __blk_recalc_rq_segments+0x14 (blk_recount_segments+0x28) : +func -1738+ 1.600 page_address+0x10 (blk_rq_bio_prep+0x60) : +func -1737 0.680 _raw_spin_lock_irq+0x10 (blk_queue_bio+0x2d8) :| +begin 0x80000001 -1736 0.960 _raw_spin_lock_irq+0x30 (blk_queue_bio+0x2d8) :| #end 0x80000001 -1735+ 1.640 _raw_spin_lock_irq+0x50 (blk_queue_bio+0x2d8) : #func -1733+ 2.520 drive_stat_acct+0x10 (blk_queue_bio+0x2e8) : #func -1731+ 2.320 disk_map_sector_rcu+0x10 (drive_stat_acct+0x94) : #func -1728+ 1.360 part_round_stats+0x10 (drive_stat_acct+0xe4) : #func -1727+ 1.240 part_round_stats_single.isra.16+0x10 (part_round_stats+0x48) : #func -1726+ 1.120 part_round_stats_single.isra.16+0x10 (part_round_stats+0x54) : #func -1725+ 3.440 __elv_add_request+0x10 (blk_queue_bio+0x2f8) : #func -1721+ 2.440 elv_rqhash_add+0x10 (__elv_add_request+0x264) : #func -1719 0.760 cfq_insert_request+0x10 (__elv_add_request+0x214) : #func -1718+ 2.280 cfq_init_prio_data+0x10 (cfq_insert_request+0x30) : #func -1716+ 1.120 cfq_add_rq_rb+0x14 (cfq_insert_request+0x78) : #func -1715+ 1.360 elv_rb_add+0x10 (cfq_add_rq_rb+0x54) : #func -1713+ 1.520 cfq_choose_req+0x14 (cfq_add_rq_rb+0xd0) : #func -1712+ 3.160 cfq_prio_tree_add+0x10 (cfq_add_rq_rb+0xe8) : #func -1709+ 1.120 __cfq_update_io_thinktime+0x10 (cfq_insert_request+0xb4) : #func -1708+ 4.200 __cfq_update_io_thinktime+0x10 (cfq_insert_request+0xc4) : #func -1703+ 1.320 __blk_run_queue+0x10 (blk_queue_bio+0x300) : #func -1702+ 2.000 mmc_request_fn+0x10 (__blk_run_queue+0x44) : #func -1700+ 1.280 wake_up_process+0x10 (mmc_request_fn+0x78) : #func -1699 0.720 try_to_wake_up+0x10 (wake_up_process+0x40) : #func -1698 1.000 _raw_spin_lock_irqsave+0x10 (try_to_wake_up+0x2c) :| #begin 0x80000001 -1697 0.680 _raw_spin_lock_irqsave+0x30 (try_to_wake_up+0x2c) :| #end 0x80000001 -1696+ 1.480 _raw_spin_lock_irqsave+0x50 (try_to_wake_up+0x2c) : #func -1695+ 1.320 _raw_spin_lock+0x10 (try_to_wake_up+0x60) : #func -1694+ 1.040 activate_task+0x10 (try_to_wake_up+0x70) : #func -1693 1.000 enqueue_task+0x10 (activate_task+0x38) : #func -1692+ 2.200 update_rq_clock+0x10 (enqueue_task+0x24) : #func -1689+ 2.360 enqueue_task_fair+0x14 (enqueue_task+0x58) : #func -1687+ 2.560 update_curr+0x14 (enqueue_task_fair+0x58) : #func -1684+ 2.880 update_min_vruntime+0x10 (update_curr+0xc0) : #func -1682+ 3.440 update_cfs_shares+0x10 (enqueue_task_fair+0xa8) : #func -1678+ 1.960 __enqueue_entity+0x10 (enqueue_task_fair+0x360) : #func -1676+ 1.160 ttwu_do_wakeup.constprop.74+0x10 (try_to_wake_up+0xd8) : #func -1675+ 1.480 check_preempt_curr+0x10 (ttwu_do_wakeup.constprop.74+0x60) : #func -1673+ 2.160 check_preempt_wakeup+0x10 (check_preempt_curr+0x38) : #func -1671 0.960 update_curr+0x14 (check_preempt_wakeup+0x130) : #func -1670+ 1.320 wakeup_preempt_entity+0x10 (check_preempt_wakeup+0x148) : #func -1669 0.800 set_next_buddy+0x10 (check_preempt_wakeup+0x160) : #func -1668+ 1.200 resched_task+0x10 (check_preempt_wakeup+0x168) :| #begin 0x80000001 -1667+ 1.040 resched_task+0x44 (check_preempt_wakeup+0x168) :| #end 0x80000001 -1666 0.960 resched_task+0x60 (check_preempt_wakeup+0x168) : #func -1665+ 1.400 _raw_spin_unlock+0x10 (try_to_wake_up+0xe0) : #func -1664 1.000 _raw_spin_unlock_irqrestore+0x10 (try_to_wake_up+0x134) : #func -1663 0.720 _raw_spin_unlock_irq+0x10 (blk_queue_bio+0x308) : #func -1662 1.000 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -1661 0.800 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -1660 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1659+ 2.400 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -1657+ 1.240 bio_put+0x10 (submit_bh+0x254) : +func -1656 0.720 ipipe_root_only+0x10 (ext4_bread+0x54) : +func -1655 1.000 _cond_resched+0x10 (ext4_bread+0x58) : +func -1654 0.640 __cond_resched+0x10 (_cond_resched+0x48) : +func -1653 1.000 ipipe_root_only+0x10 (__cond_resched+0x18) : +func -1652 0.720 __schedule+0x14 (__cond_resched+0x34) : +func -1652 0.680 rcu_sched_qs+0x10 (__schedule+0x34) :| +begin 0x80000001 -1651+ 1.200 rcu_sched_qs+0x2c (__schedule+0x34) :| #end 0x80000001 -1650+ 1.120 rcu_sched_qs+0x4c (__schedule+0x34) : #func -1649 0.920 ipipe_unstall_root+0x10 (rcu_sched_qs+0xd4) :| #begin 0x80000000 -1648 0.760 ipipe_unstall_root+0x2c (rcu_sched_qs+0xd4) :| #func -1647 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1646 0.760 ipipe_unstall_root+0x64 (rcu_sched_qs+0xd4) : +func -1646+ 1.040 ipipe_root_only+0x10 (__schedule+0x48) : +func -1644 0.640 _raw_spin_lock_irq+0x10 (__schedule+0x9c) :| +begin 0x80000001 -1644+ 1.320 _raw_spin_lock_irq+0x30 (__schedule+0x9c) :| #end 0x80000001 -1643+ 1.200 _raw_spin_lock_irq+0x50 (__schedule+0x9c) : #func -1641+ 1.240 update_rq_clock+0x10 (__schedule+0x1e4) : #func -1640+ 1.240 put_prev_task_fair+0x10 (__schedule+0x1f8) : #func -1639 0.960 update_curr+0x14 (put_prev_task_fair+0x38) : #func -1638+ 2.320 update_min_vruntime+0x10 (update_curr+0xc0) : #func -1636+ 1.800 cpuacct_charge+0x10 (update_curr+0x12c) : #func -1634+ 1.400 __enqueue_entity+0x10 (put_prev_task_fair+0xac) : #func -1632 1.000 update_curr+0x14 (put_prev_task_fair+0x38) : #func -1631+ 1.960 __enqueue_entity+0x10 (put_prev_task_fair+0xac) : #func -1629+ 1.040 pick_next_task_fair+0x10 (__schedule+0x220) : #func -1628 0.960 __pick_first_entity+0x10 (pick_next_task_fair+0x2c) : #func -1627+ 1.040 wakeup_preempt_entity+0x10 (pick_next_task_fair+0x9c) : #func -1626+ 1.600 clear_buddies+0x10 (pick_next_task_fair+0xb0) : #func -1625 1.000 set_next_entity+0x10 (pick_next_task_fair+0xbc) : #func -1624+ 1.560 update_stats_wait_end+0x10 (set_next_entity+0x2c) : #func -1622+ 3.120 __dequeue_entity+0x10 (set_next_entity+0x38) :| #begin 0x80000001 -1619 0.680 __schedule+0x274 (__cond_resched+0x34) :| #end 0x80000001 -1618+ 3.200 __schedule+0x298 (__cond_resched+0x34) :| #begin 0x80000000 -1615+ 2.160 __schedule+0x464 (__cond_resched+0x34) :| #func -1613+ 1.440 __ipipe_switch_to_notifier_call_chain+0x10 (__switch_to+0x2c) :| #func -1612 1.000 atomic_notifier_call_chain+0x14 (__ipipe_switch_to_notifier_call_chain+0x6c) :| #func -1611 0.680 __atomic_notifier_call_chain+0x14 (atomic_notifier_call_chain+0x28) :| #func -1610 0.760 notifier_call_chain+0x10 (__atomic_notifier_call_chain+0x28) :| #func -1609+ 1.680 vfp_notifier+0x10 (notifier_call_chain+0x48) :| #func -1607+ 2.160 thumbee_notifier+0x10 (notifier_call_chain+0x48) :| #func -1605+ 2.240 __ipipe_restore_root_nosync+0x10 (__ipipe_switch_to_notifier_call_chain+0x7c) :| #func -1603+ 1.160 __ipipe_switch_tail+0x10 (__schedule+0x504) :| #end 0x80000000 -1602 0.760 __ipipe_switch_tail+0x70 (__schedule+0x504) : #func -1601 1.000 finish_task_switch.constprop.72+0x10 (__schedule+0x514) : #func -1600+ 1.160 _raw_spin_unlock_irq+0x10 (finish_task_switch.constprop.72+0x60) : #func -1599 0.680 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -1598+ 1.080 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -1597 0.760 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1596+ 3.520 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -1593 0.720 down+0x10 (mmc_queue_thread+0x44) : +func -1592 0.640 _raw_spin_lock_irqsave+0x10 (down+0x1c) :| +begin 0x80000001 -1592+ 1.440 _raw_spin_lock_irqsave+0x30 (down+0x1c) :| #end 0x80000001 -1590+ 1.640 _raw_spin_lock_irqsave+0x50 (down+0x1c) : #func -1589 0.800 _raw_spin_unlock_irqrestore+0x10 (down+0x48) : #func -1588 0.920 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1587 0.760 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1586+ 1.040 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1585 0.720 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -1584 0.720 _raw_spin_lock_irq+0x10 (mmc_queue_thread+0x4c) :| +begin 0x80000001 -1584 0.720 _raw_spin_lock_irq+0x30 (mmc_queue_thread+0x4c) :| #end 0x80000001 -1583+ 1.360 _raw_spin_lock_irq+0x50 (mmc_queue_thread+0x4c) : #func -1581 0.880 blk_fetch_request+0x10 (mmc_queue_thread+0x60) : #func -1581+ 1.840 blk_peek_request+0x10 (blk_fetch_request+0x18) : #func -1579+ 2.120 cfq_dispatch_requests+0x14 (blk_peek_request+0x1e0) :| #begin 0x90000000 -1577+ 1.160 __irq_svc+0x44 (cfq_dispatch_requests+0x1b8) :| #func -1575+ 1.320 omap3_intc_handle_irq+0x10 (__irq_svc+0x58) :| #func -1574 0.920 irq_find_mapping+0x10 (omap3_intc_handle_irq+0x64) :| #func -1573+ 1.480 irq_domain_legacy_revmap+0x10 (irq_find_mapping+0x5c) :| #func -1572 0.680 __ipipe_grab_irq+0x10 (omap3_intc_handle_irq+0x70) :| #begin 0x00000053 -1571 1.000 __ipipe_grab_irq+0x24 (omap3_intc_handle_irq+0x70) :| #func -1570+ 1.040 __ipipe_dispatch_irq+0x10 (__ipipe_grab_irq+0x8c) :| #func -1569+ 1.680 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x4c) :| #func -1567+ 1.680 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x2ac) :| #func -1566 0.720 __ipipe_ack_hrtimer_irq+0x10 (__ipipe_dispatch_irq+0xd8) :| #func -1565 0.720 __ipipe_ack_level_irq+0x10 (__ipipe_ack_hrtimer_irq+0x30) :| #func -1564+ 1.320 omap_mask_ack_irq+0x10 (__ipipe_ack_level_irq+0x4c) :| #func -1563+ 1.280 irq_gc_mask_disable_reg+0x10 (omap_mask_ack_irq+0x18) :| #func -1562+ 1.040 omap2_gp_timer_ack+0x10 (__ipipe_ack_hrtimer_irq+0x40) :| #func -1561 0.960 __ipipe_end_level_irq+0x10 (__ipipe_ack_hrtimer_irq+0x58) :| #func -1560+ 1.440 irq_gc_unmask_enable_reg+0x10 (__ipipe_end_level_irq+0x24) :| #*func -1558+ 2.360 xnintr_clock_handler+0x14 (__ipipe_dispatch_irq+0x1cc) :| #*func -1556+ 1.520 xntimer_tick_aperiodic+0x14 (xnintr_clock_handler+0x128) :| #*func -1554 1.000 xnthread_periodic_handler+0x10 (xntimer_tick_aperiodic+0xac) :| #*func -1553+ 1.440 xnpod_resume_thread+0x14 (xnthread_periodic_handler+0x30) :| #*[ 3238] samplin 99 -1552+ 1.960 xnpod_resume_thread+0x108 (xnthread_periodic_handler+0x30) :| #*func -1550+ 1.160 xntimer_next_local_shot+0x10 (xntimer_tick_aperiodic+0x208) :| #*event tick@-1277 -1549 0.920 xntimer_next_local_shot+0xd0 (xntimer_tick_aperiodic+0x208) :| #*func -1548 0.760 ipipe_timer_set+0x10 (xntimer_next_local_shot+0xd8) :| #*func -1547+ 2.760 omap2_gp_timer_set_next_event+0x10 (ipipe_timer_set+0x64) :| #*func -1544+ 1.920 __xnpod_schedule+0x14 (xnintr_clock_handler+0x29c) :| #*[ 3827] -<?>- -1 -1542 0.680 __xnpod_schedule+0x134 (xnintr_clock_handler+0x29c) :| #*func -1542+ 2.680 xnsched_pick_next+0x10 (__xnpod_schedule+0x160) :| #*func -1539+ 3.160 check_and_switch_context+0x14 (__xnpod_schedule+0x3ec) :| #*[ 3238] samplin 99 -1536+ 2.520 __xnpod_schedule+0x45c (xnpod_suspend_thread+0x444) :| #*func -1533+ 1.960 xntimer_get_overruns+0x14 (xnpod_wait_thread_period+0x168) :| #*func -1531 0.880 __ipipe_restore_head+0x10 (xnpod_wait_thread_period+0x2e8) :| +*end 0x80000000 -1531+ 1.480 __ipipe_restore_head+0x108 (xnpod_wait_thread_period+0x2e8) : +*func -1529+ 1.040 __ipipe_uaccess_might_fault+0x10 (__rt_task_wait_period+0x48) :| +*begin 0x80000001 -1528 0.920 __ipipe_uaccess_might_fault+0x2c (__rt_task_wait_period+0x48) :| +*end 0x80000001 -1527+ 2.200 __ipipe_uaccess_might_fault+0x8c (__rt_task_wait_period+0x48) :| +*begin 0x80000001 -1525+ 1.240 __ipipe_notify_syscall+0xc0 (__ipipe_syscall_root+0x84) :| +*end 0x80000001 -1524 0.760 __ipipe_notify_syscall+0x138 (__ipipe_syscall_root+0x84) :| +*begin 0x80000000 -1523+ 1.240 __ipipe_syscall_root+0xa0 (vector_swi+0x7c) :| +*end 0x80000000 -1522 0.880 __ipipe_syscall_root+0x11c (vector_swi+0x7c) :| +*func -1521 0.960 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_ret_to_user_irqs_disabled+0x4) :| +*end 0x90000000 -1520+ 4.400 __ipipe_ret_to_user_irqs_disabled+0x18 (<b6f245e0>) :| +*begin 0x90000000 -1515+ 1.120 vector_swi+0x3c (<b6f245dc>) : +*func -1514+ 1.080 __ipipe_syscall_root+0x10 (vector_swi+0x7c) : +*func -1513 0.680 __ipipe_notify_syscall+0x14 (__ipipe_syscall_root+0x84) :| +*begin 0x80000001 -1513 0.720 __ipipe_notify_syscall+0x34 (__ipipe_syscall_root+0x84) :| +*end 0x80000001 -1512+ 1.200 __ipipe_notify_syscall+0x94 (__ipipe_syscall_root+0x84) : +*func -1511+ 1.120 ipipe_syscall_hook+0x10 (__ipipe_notify_syscall+0xa4) : +*func -1509+ 1.720 hisyscall_event+0x14 (ipipe_syscall_hook+0x44) : +*func -1508 0.720 __rt_task_wait_period+0x14 (hisyscall_event+0x17c) : +*func -1507 0.720 rt_task_wait_period+0x10 (__rt_task_wait_period+0x24) : +*func -1506 0.960 xnpod_wait_thread_period+0x14 (rt_task_wait_period+0x48) :| +*begin 0x80000000 -1505+ 1.680 xnpod_wait_thread_period+0x3c (rt_task_wait_period+0x48) :| #*func -1504+ 1.760 xnpod_suspend_thread+0x14 (xnpod_wait_thread_period+0x144) :| #*func -1502+ 1.200 __xnpod_schedule+0x14 (xnpod_suspend_thread+0x444) :| #*[ 3238] samplin 99 -1501 0.680 __xnpod_schedule+0x134 (xnpod_suspend_thread+0x444) :| #*func -1500+ 1.920 xnsched_pick_next+0x10 (__xnpod_schedule+0x160) :| #*func -1498+ 2.160 check_and_switch_context+0x14 (__xnpod_schedule+0x3ec) :| #*[ 66] mmcqd/0 -1 -1496+ 2.360 __xnpod_schedule+0x45c (xnintr_clock_handler+0x29c) :| #func -1494+ 1.480 __ipipe_do_sync_pipeline+0x10 (__ipipe_dispatch_irq+0x28c) :| #end 0x00000053 -1492 0.680 __ipipe_grab_irq+0x94 (omap3_intc_handle_irq+0x70) :| #func -1491+ 1.680 __ipipe_exit_irq+0x10 (__ipipe_grab_irq+0x9c) :| #func -1490+ 1.360 __ipipe_check_root_interruptible+0x10 (__irq_svc+0x5c) :| #func -1488 0.680 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_fast_svc_irq_exit+0x4) :| #end 0x90000000 -1488+ 2.120 __ipipe_fast_svc_irq_exit+0x18 (cfq_dispatch_requests+0x1b8) : #func -1486+ 3.960 cfq_should_idle+0x10 (cfq_dispatch_requests+0x674) : #func -1482+ 1.040 cfq_dispatch_insert+0x10 (cfq_dispatch_requests+0x7e8) : #func -1481+ 2.720 cfq_find_next_rq+0x14 (cfq_dispatch_insert+0x38) : #func -1478 0.800 cfq_choose_req+0x14 (cfq_find_next_rq+0x98) : #func -1477+ 1.440 cfq_remove_request+0x10 (cfq_dispatch_insert+0x44) : #func -1476+ 3.640 elv_rb_del+0x10 (cfq_remove_request+0x90) : #func -1472 0.680 elv_dispatch_sort+0x10 (cfq_dispatch_insert+0x6c) : #func -1471+ 3.520 elv_rqhash_del.isra.1+0x10 (elv_dispatch_sort+0x34) : #func -1468+ 2.320 cfq_activate_request+0x10 (blk_peek_request+0x64) : #func -1465+ 2.400 mmc_prep_request+0x10 (blk_peek_request+0x114) : #func -1463+ 1.280 blk_start_request+0x10 (blk_fetch_request+0x24) : #func -1462+ 1.960 blk_dequeue_request+0x10 (blk_start_request+0x1c) : #func -1460+ 1.360 blk_add_timer+0x10 (blk_start_request+0x3c) : #func -1458+ 1.200 _raw_spin_unlock_irq+0x10 (mmc_queue_thread+0x74) : #func -1457 0.760 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -1457+ 1.280 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -1455 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1454+ 1.560 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -1453+ 1.280 mmc_blk_issue_rq+0x14 (mmc_queue_thread+0xa8) : +func -1451+ 1.960 __mmc_claim_host+0x14 (mmc_blk_issue_rq+0x44) : +func -1449 0.800 ipipe_root_only+0x10 (__mmc_claim_host+0x5c) : +func -1449+ 1.240 _cond_resched+0x10 (__mmc_claim_host+0x60) : +func -1447 0.720 add_wait_queue+0x10 (__mmc_claim_host+0x6c) : +func -1447 0.680 _raw_spin_lock_irqsave+0x10 (add_wait_queue+0x30) :| +begin 0x80000001 -1446+ 1.080 _raw_spin_lock_irqsave+0x30 (add_wait_queue+0x30) :| #end 0x80000001 -1445+ 1.720 _raw_spin_lock_irqsave+0x50 (add_wait_queue+0x30) : #func -1443+ 1.080 _raw_spin_unlock_irqrestore+0x10 (add_wait_queue+0x54) : #func -1442 0.680 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1441 0.760 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1441 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1440 0.960 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -1439 0.640 _raw_spin_lock_irqsave+0x10 (__mmc_claim_host+0x74) :| +begin 0x80000001 -1438 0.760 _raw_spin_lock_irqsave+0x30 (__mmc_claim_host+0x74) :| #end 0x80000001 -1437+ 2.080 _raw_spin_lock_irqsave+0x50 (__mmc_claim_host+0x74) : #func -1435 1.000 _raw_spin_unlock_irqrestore+0x10 (__mmc_claim_host+0x144) : #func -1434 0.680 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1434 0.760 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1433 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1432 0.960 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -1431 0.680 remove_wait_queue+0x10 (__mmc_claim_host+0x150) : +func -1430 0.640 _raw_spin_lock_irqsave+0x10 (remove_wait_queue+0x20) :| +begin 0x80000001 -1430 0.760 _raw_spin_lock_irqsave+0x30 (remove_wait_queue+0x20) :| #end 0x80000001 -1429+ 1.320 _raw_spin_lock_irqsave+0x50 (remove_wait_queue+0x20) : #func -1427 0.760 _raw_spin_unlock_irqrestore+0x10 (remove_wait_queue+0x4c) : #func -1427 0.680 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1426+ 1.040 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1425 0.760 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1424+ 1.400 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -1423+ 1.400 omap_hsmmc_enable_fclk+0x10 (__mmc_claim_host+0x17c) : +func -1421+ 1.240 __pm_runtime_resume+0x10 (omap_hsmmc_enable_fclk+0x20) : +func -1420 0.680 ipipe_root_only+0x10 (__pm_runtime_resume+0x34) : +func -1419 0.920 _cond_resched+0x10 (__pm_runtime_resume+0x38) : +func -1419 0.680 _raw_spin_lock_irqsave+0x10 (__pm_runtime_resume+0x64) :| +begin 0x80000001 -1418 0.960 _raw_spin_lock_irqsave+0x30 (__pm_runtime_resume+0x64) :| #end 0x80000001 -1417+ 1.520 _raw_spin_lock_irqsave+0x50 (__pm_runtime_resume+0x64) : #func -1415+ 3.400 rpm_resume+0x14 (__pm_runtime_resume+0x74) : #func -1412 0.800 _raw_spin_unlock_irqrestore+0x10 (__pm_runtime_resume+0x84) : #func -1411 0.680 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1411+ 1.080 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1409 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1409+ 1.040 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -1408+ 3.160 dev_get_drvdata+0x10 (mmc_blk_issue_rq+0x4c) : +func -1405+ 1.840 mmc_blk_issue_rw_rq+0x14 (mmc_blk_issue_rq+0x434) : +func -1403+ 4.400 mmc_blk_rw_rq_prep+0x10 (mmc_blk_issue_rw_rq+0x9c) : +func -1398+ 4.320 mmc_set_data_timeout+0x10 (mmc_blk_rw_rq_prep+0x268) : +func -1394+ 1.160 mmc_queue_map_sg+0x10 (mmc_blk_rw_rq_prep+0x27c) : +func -1393+ 1.960 blk_rq_map_sg+0x14 (mmc_queue_map_sg+0x34) : +func -1391+ 3.600 __blk_segment_map_sg+0x14 (blk_rq_map_sg+0xa0) : +func -1387+ 1.640 mmc_queue_bounce_pre+0x10 (mmc_blk_rw_rq_prep+0x2e8) : +func -1386+ 1.480 mmc_start_req+0x10 (mmc_blk_issue_rw_rq+0xb8) : +func -1384+ 2.080 omap_hsmmc_pre_req+0x10 (mmc_start_req+0x48) : +func -1382+ 2.520 omap_hsmmc_pre_dma_transfer+0x14 (omap_hsmmc_pre_req+0x5c) : +func -1380+ 2.400 page_address+0x10 (omap_hsmmc_pre_dma_transfer+0xc8) : +func -1377+ 1.960 arm_dma_map_sg+0x14 (omap_hsmmc_pre_dma_transfer+0x100) : +func -1375+ 2.000 arm_dma_map_page+0x10 (arm_dma_map_sg+0x74) : +func -1373+ 1.720 __dma_page_cpu_to_dev+0x14 (arm_dma_map_page+0x48) : +func -1371+ 1.400 dma_cache_maint_page+0x10 (__dma_page_cpu_to_dev+0x34) : +func -1370+ 7.960 page_address+0x10 (dma_cache_maint_page+0x108) : +func -1362 0.920 __mmc_start_req+0x10 (mmc_start_req+0xe4) : +func -1361+ 3.200 __init_waitqueue_head+0x10 (__mmc_start_req+0x38) : +func -1358+ 1.160 led_trigger_event+0x10 (__mmc_start_req+0x130) : +func -1357+ 1.920 _raw_read_lock+0x10 (led_trigger_event+0x2c) : +func -1355+ 1.760 led_set_brightness+0x10 (led_trigger_event+0x40) : +func -1353+ 1.920 gpio_led_set+0x10 (led_set_brightness+0x64) : +func -1351+ 2.320 __gpio_set_value+0x10 (gpio_led_set+0x78) : +func -1349 0.920 gpio_set+0x10 (__gpio_set_value+0xe0) : +func -1348 0.720 __ipipe_spin_lock_irqsave+0x10 (gpio_set+0x30) :| +begin 0x80000001 -1347+ 1.200 __ipipe_spin_lock_irqsave+0x30 (gpio_set+0x30) :| #func -1346+ 2.960 _set_gpio_dataout_reg+0x10 (gpio_set+0x48) :| #func -1343 0.960 __ipipe_spin_unlock_irqrestore+0x10 (gpio_set+0x54) :| +end 0x80000001 -1342+ 1.120 __ipipe_spin_unlock_irqrestore+0x50 (gpio_set+0x54) : +func -1341+ 1.680 _raw_read_unlock+0x10 (led_trigger_event+0x54) : +func -1339+ 2.280 omap_hsmmc_request+0x14 (__mmc_start_req+0x144) : +func -1337+ 1.760 set_data_timeout+0x10 (omap_hsmmc_request+0x27c) : +func -1335+ 1.120 clk_get_rate+0x10 (set_data_timeout+0x3c) : +func -1334 0.680 mutex_lock+0x10 (clk_get_rate+0x20) : +func -1333 0.720 ipipe_root_only+0x10 (mutex_lock+0x1c) : +func -1333+ 1.040 _cond_resched+0x10 (mutex_lock+0x20) : +func -1332+ 1.480 __mutex_lock_slowpath+0x14 (mutex_lock+0x28) :| +begin 0x80000001 -1330+ 1.320 __mutex_lock_slowpath+0x90 (mutex_lock+0x28) :| #end 0x80000001 -1329+ 3.880 __mutex_lock_slowpath+0xb0 (mutex_lock+0x28) : #func -1325 0.960 ipipe_unstall_root+0x10 (__mutex_lock_slowpath+0x2d0) :| #begin 0x80000000 -1324 0.720 ipipe_unstall_root+0x2c (__mutex_lock_slowpath+0x2d0) :| #func -1323 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1322+ 2.440 ipipe_unstall_root+0x64 (__mutex_lock_slowpath+0x2d0) : +func -1320 0.960 __clk_get_rate+0x10 (clk_get_rate+0x48) : +func -1319 0.920 mutex_unlock+0x10 (clk_get_rate+0x54) : +func -1318+ 1.280 __mutex_unlock_slowpath+0x10 (mutex_unlock+0x18) :| +begin 0x80000001 -1317+ 1.040 __mutex_unlock_slowpath+0x88 (mutex_unlock+0x18) :| #end 0x80000001 -1316+ 2.640 __mutex_unlock_slowpath+0xa8 (mutex_unlock+0x18) : #func -1313 0.680 ipipe_unstall_root+0x10 (__mutex_unlock_slowpath+0x148) :| #begin 0x80000000 -1312 1.000 ipipe_unstall_root+0x2c (__mutex_unlock_slowpath+0x148) :| #func -1311 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1311+ 3.520 ipipe_unstall_root+0x64 (__mutex_unlock_slowpath+0x148) : +func -1307+ 1.960 edma_control+0x14 (omap_hsmmc_request+0x338) : +func -1305+ 1.400 omap_hsmmc_pre_dma_transfer+0x14 (omap_hsmmc_request+0x354) : +func -1304+ 1.800 edma_prep_slave_sg+0x14 (omap_hsmmc_request+0x38c) : +func -1302+ 1.120 __kmalloc+0x14 (edma_prep_slave_sg+0xec) :| +begin 0x80000001 -1301+ 1.040 __kmalloc+0x90 (edma_prep_slave_sg+0xec) :| #end 0x80000001 -1300+ 2.280 __kmalloc+0xb4 (edma_prep_slave_sg+0xec) : #func -1298 0.640 ipipe_unstall_root+0x10 (__kmalloc+0x114) :| #begin 0x80000000 -1297 0.960 ipipe_unstall_root+0x2c (__kmalloc+0x114) :| #func -1296 1.000 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1295+ 5.360 ipipe_unstall_root+0x64 (__kmalloc+0x114) : +func -1290+ 1.760 dma_async_tx_descriptor_init+0x10 (edma_prep_slave_sg+0x2cc) : +func -1288 0.960 vchan_tx_submit+0x10 (omap_hsmmc_request+0x3c0) : +func -1287 0.680 _raw_spin_lock_irqsave+0x10 (vchan_tx_submit+0x28) :| +begin 0x80000001 -1286 0.760 _raw_spin_lock_irqsave+0x30 (vchan_tx_submit+0x28) :| #end 0x80000001 -1285+ 1.640 _raw_spin_lock_irqsave+0x50 (vchan_tx_submit+0x28) : #func -1284 0.800 _raw_spin_unlock_irqrestore+0x10 (vchan_tx_submit+0x6c) : #func -1283 0.960 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1282 0.760 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1281 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1281+ 1.160 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -1279 0.680 edma_issue_pending+0x10 (omap_hsmmc_request+0x3d8) : +func -1279 0.680 _raw_spin_lock_irqsave+0x10 (edma_issue_pending+0x24) :| +begin 0x80000001 -1278 1.000 _raw_spin_lock_irqsave+0x30 (edma_issue_pending+0x24) :| #end 0x80000001 -1277+ 1.600 _raw_spin_lock_irqsave+0x50 (edma_issue_pending+0x24) : #func -1275+ 1.840 edma_execute+0x10 (edma_issue_pending+0x7c) : #func -1274+ 1.040 edma_write_slot+0x10 (edma_execute+0x78) :| #begin 0x90000000 -1273+ 1.160 __irq_svc+0x44 (__ipipe_trace+0x408) :| #func -1271+ 1.640 omap3_intc_handle_irq+0x10 (__irq_svc+0x58) :| #func -1270+ 1.400 irq_find_mapping+0x10 (omap3_intc_handle_irq+0x64) :| #func -1268+ 1.120 irq_domain_legacy_revmap+0x10 (irq_find_mapping+0x5c) :| #func -1267 0.640 __ipipe_grab_irq+0x10 (omap3_intc_handle_irq+0x70) :| #begin 0x00000053 -1267 0.800 __ipipe_grab_irq+0x24 (omap3_intc_handle_irq+0x70) :| #func -1266+ 1.280 __ipipe_dispatch_irq+0x10 (__ipipe_grab_irq+0x8c) :| #func -1265+ 1.720 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x4c) :| #func -1263 1.000 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x2ac) :| #func -1262 0.920 __ipipe_ack_hrtimer_irq+0x10 (__ipipe_dispatch_irq+0xd8) :| #func -1261 0.720 __ipipe_ack_level_irq+0x10 (__ipipe_ack_hrtimer_irq+0x30) :| #func -1260+ 1.240 omap_mask_ack_irq+0x10 (__ipipe_ack_level_irq+0x4c) :| #func -1259+ 1.120 irq_gc_mask_disable_reg+0x10 (omap_mask_ack_irq+0x18) :| #func -1258+ 1.120 omap2_gp_timer_ack+0x10 (__ipipe_ack_hrtimer_irq+0x40) :| #func -1257 0.960 __ipipe_end_level_irq+0x10 (__ipipe_ack_hrtimer_irq+0x58) :| #func -1256+ 1.760 irq_gc_unmask_enable_reg+0x10 (__ipipe_end_level_irq+0x24) :| #*func -1254+ 2.200 xnintr_clock_handler+0x14 (__ipipe_dispatch_irq+0x1cc) :| #*func -1252+ 1.840 xntimer_tick_aperiodic+0x14 (xnintr_clock_handler+0x128) :| #*func -1250 0.960 xnthread_periodic_handler+0x10 (xntimer_tick_aperiodic+0xac) :| #*func -1249+ 1.160 xnpod_resume_thread+0x14 (xnthread_periodic_handler+0x30) :| #*[ 3783] servo-t 98 -1248+ 2.400 xnpod_resume_thread+0x108 (xnthread_periodic_handler+0x30) :| #*func -1245+ 1.080 xntimer_next_local_shot+0x10 (xntimer_tick_aperiodic+0x208) :| #*event tick@-1100 -1244 0.920 xntimer_next_local_shot+0xd0 (xntimer_tick_aperiodic+0x208) :| #*func -1243 0.720 ipipe_timer_set+0x10 (xntimer_next_local_shot+0xd8) :| #*func -1243+ 2.520 omap2_gp_timer_set_next_event+0x10 (ipipe_timer_set+0x64) :| #*func -1240+ 1.760 __xnpod_schedule+0x14 (xnintr_clock_handler+0x29c) :| #*[ 66] mmcqd/0 -1 -1238 0.640 __xnpod_schedule+0x134 (xnintr_clock_handler+0x29c) :| #*func -1238+ 2.600 xnsched_pick_next+0x10 (__xnpod_schedule+0x160) :| #*func -1235+ 2.720 check_and_switch_context+0x14 (__xnpod_schedule+0x3ec) :| #*[ 3783] servo-t 98 -1232+ 3.000 __xnpod_schedule+0x45c (xnpod_suspend_thread+0x444) :| #*func -1229+ 1.760 xntimer_get_overruns+0x14 (xnpod_wait_thread_period+0x168) :| #*func -1228 0.880 __ipipe_restore_head+0x10 (xnpod_wait_thread_period+0x2e8) :| +*end 0x80000000 -1227+ 1.160 __ipipe_restore_head+0x108 (xnpod_wait_thread_period+0x2e8) : +*func -1226+ 1.080 __ipipe_uaccess_might_fault+0x10 (__rt_task_wait_period+0x48) :| +*begin 0x80000001 -1225+ 1.480 __ipipe_uaccess_might_fault+0x2c (__rt_task_wait_period+0x48) :| +*end 0x80000001 -1223+ 2.720 __ipipe_uaccess_might_fault+0x8c (__rt_task_wait_period+0x48) :| +*begin 0x80000001 -1220 0.880 __ipipe_notify_syscall+0xc0 (__ipipe_syscall_root+0x84) :| +*end 0x80000001 -1219 0.720 __ipipe_notify_syscall+0x138 (__ipipe_syscall_root+0x84) :| +*begin 0x80000000 -1219+ 1.160 __ipipe_syscall_root+0xa0 (vector_swi+0x7c) :| +*end 0x80000000 -1218 0.800 __ipipe_syscall_root+0x11c (vector_swi+0x7c) :| +*func -1217 0.720 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_ret_to_user_irqs_disabled+0x4) :| +*end 0x90000000 -1216! 89.160 __ipipe_ret_to_user_irqs_disabled+0x18 (<b6f2f5e0>) :| +*begin 0x90000000 -1127+ 2.040 vector_swi+0x3c (<b6f2f5dc>) : +*func -1125+ 1.160 __ipipe_syscall_root+0x10 (vector_swi+0x7c) : +*func -1124 0.680 __ipipe_notify_syscall+0x14 (__ipipe_syscall_root+0x84) :| +*begin 0x80000001 -1123 0.720 __ipipe_notify_syscall+0x34 (__ipipe_syscall_root+0x84) :| +*end 0x80000001 -1122+ 1.280 __ipipe_notify_syscall+0x94 (__ipipe_syscall_root+0x84) : +*func -1121 0.800 ipipe_syscall_hook+0x10 (__ipipe_notify_syscall+0xa4) : +*func -1120+ 1.280 hisyscall_event+0x14 (ipipe_syscall_hook+0x44) : +*func -1119+ 1.080 __rt_task_wait_period+0x14 (hisyscall_event+0x17c) : +*func -1118 0.840 rt_task_wait_period+0x10 (__rt_task_wait_period+0x24) : +*func -1117 1.000 xnpod_wait_thread_period+0x14 (rt_task_wait_period+0x48) :| +*begin 0x80000000 -1116+ 2.120 xnpod_wait_thread_period+0x3c (rt_task_wait_period+0x48) :| #*func -1114+ 1.440 xnpod_suspend_thread+0x14 (xnpod_wait_thread_period+0x144) :| #*func -1112+ 1.280 __xnpod_schedule+0x14 (xnpod_suspend_thread+0x444) :| #*[ 3783] servo-t 98 -1111 0.960 __xnpod_schedule+0x134 (xnpod_suspend_thread+0x444) :| #*func -1110+ 2.360 xnsched_pick_next+0x10 (__xnpod_schedule+0x160) :| #*func -1108+ 2.520 check_and_switch_context+0x14 (__xnpod_schedule+0x3ec) :| #*[ 66] mmcqd/0 -1 -1105+ 2.880 __xnpod_schedule+0x45c (xnintr_clock_handler+0x29c) :| #func -1102+ 1.760 __ipipe_do_sync_pipeline+0x10 (__ipipe_dispatch_irq+0x28c) :| #end 0x00000053 -1101 0.680 __ipipe_grab_irq+0x94 (omap3_intc_handle_irq+0x70) :| #func -1100+ 1.520 __ipipe_exit_irq+0x10 (__ipipe_grab_irq+0x9c) :| #func -1099+ 1.440 __ipipe_check_root_interruptible+0x10 (__irq_svc+0x5c) :| #func -1097 0.680 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_fast_svc_irq_exit+0x4) :| #end 0x90000000 -1096+ 1.160 __ipipe_fast_svc_irq_exit+0x18 (__ipipe_trace+0x408) :| #begin 0x90000000 -1095+ 1.200 __irq_svc+0x44 (__ipipe_trace+0x408) :| #func -1094 0.960 omap3_intc_handle_irq+0x10 (__irq_svc+0x58) :| #func -1093+ 1.240 irq_find_mapping+0x10 (omap3_intc_handle_irq+0x64) :| #func -1092+ 1.160 irq_domain_legacy_revmap+0x10 (irq_find_mapping+0x5c) :| #func -1091 0.680 __ipipe_grab_irq+0x10 (omap3_intc_handle_irq+0x70) :| #begin 0x00000053 -1090+ 1.040 __ipipe_grab_irq+0x24 (omap3_intc_handle_irq+0x70) :| #func -1089 0.720 __ipipe_dispatch_irq+0x10 (__ipipe_grab_irq+0x8c) :| #func -1088+ 1.160 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x4c) :| #func -1087+ 1.520 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x2ac) :| #func -1086 0.680 __ipipe_ack_hrtimer_irq+0x10 (__ipipe_dispatch_irq+0xd8) :| #func -1085+ 1.040 __ipipe_ack_level_irq+0x10 (__ipipe_ack_hrtimer_irq+0x30) :| #func -1084 0.640 omap_mask_ack_irq+0x10 (__ipipe_ack_level_irq+0x4c) :| #func -1083+ 1.200 irq_gc_mask_disable_reg+0x10 (omap_mask_ack_irq+0x18) :| #func -1082+ 1.280 omap2_gp_timer_ack+0x10 (__ipipe_ack_hrtimer_irq+0x40) :| #func -1081 0.680 __ipipe_end_level_irq+0x10 (__ipipe_ack_hrtimer_irq+0x58) :| #func -1080+ 1.440 irq_gc_unmask_enable_reg+0x10 (__ipipe_end_level_irq+0x24) :| #*func -1079+ 1.960 xnintr_clock_handler+0x14 (__ipipe_dispatch_irq+0x1cc) :| #*func -1077+ 1.120 xntimer_tick_aperiodic+0x14 (xnintr_clock_handler+0x128) :| #*func -1076 0.960 xnthread_periodic_handler+0x10 (xntimer_tick_aperiodic+0xac) :| #*func -1075 0.840 xnpod_resume_thread+0x14 (xnthread_periodic_handler+0x30) :| #*[ 3238] samplin 99 -1074+ 1.640 xnpod_resume_thread+0x108 (xnthread_periodic_handler+0x30) :| #*func -1072+ 1.440 xntimer_next_local_shot+0x10 (xntimer_tick_aperiodic+0x208) :| #*event tick@-620 -1071 0.600 xntimer_next_local_shot+0xd0 (xntimer_tick_aperiodic+0x208) :| #*func -1070 0.720 ipipe_timer_set+0x10 (xntimer_next_local_shot+0xd8) :| #*func -1069+ 1.880 omap2_gp_timer_set_next_event+0x10 (ipipe_timer_set+0x64) :| #*func -1067+ 1.240 __xnpod_schedule+0x14 (xnintr_clock_handler+0x29c) :| #*[ 66] mmcqd/0 -1 -1066 0.920 __xnpod_schedule+0x134 (xnintr_clock_handler+0x29c) :| #*func -1065+ 1.640 xnsched_pick_next+0x10 (__xnpod_schedule+0x160) :| #*func -1064+ 2.920 check_and_switch_context+0x14 (__xnpod_schedule+0x3ec) :| #*[ 3238] samplin 99 -1061+ 2.920 __xnpod_schedule+0x45c (xnpod_suspend_thread+0x444) :| #*func -1058+ 1.320 xntimer_get_overruns+0x14 (xnpod_wait_thread_period+0x168) :| #*func -1056 0.800 __ipipe_restore_head+0x10 (xnpod_wait_thread_period+0x2e8) :| +*end 0x80000000 -1056+ 1.600 __ipipe_restore_head+0x108 (xnpod_wait_thread_period+0x2e8) : +*func -1054 0.800 __ipipe_uaccess_might_fault+0x10 (__rt_task_wait_period+0x48) :| +*begin 0x80000001 -1053+ 1.200 __ipipe_uaccess_might_fault+0x2c (__rt_task_wait_period+0x48) :| +*end 0x80000001 -1052+ 2.040 __ipipe_uaccess_might_fault+0x8c (__rt_task_wait_period+0x48) :| +*begin 0x80000001 -1050 0.880 __ipipe_notify_syscall+0xc0 (__ipipe_syscall_root+0x84) :| +*end 0x80000001 -1049+ 1.040 __ipipe_notify_syscall+0x138 (__ipipe_syscall_root+0x84) :| +*begin 0x80000000 -1048+ 1.120 __ipipe_syscall_root+0xa0 (vector_swi+0x7c) :| +*end 0x80000000 -1047 0.720 __ipipe_syscall_root+0x11c (vector_swi+0x7c) :| +*func -1046 1.000 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_ret_to_user_irqs_disabled+0x4) :| +*end 0x90000000 -1045+ 4.160 __ipipe_ret_to_user_irqs_disabled+0x18 (<b6f245e0>) :| +*begin 0x90000000 -1041+ 1.280 vector_swi+0x3c (<b6f245dc>) : +*func -1040 0.760 __ipipe_syscall_root+0x10 (vector_swi+0x7c) : +*func -1039 0.640 __ipipe_notify_syscall+0x14 (__ipipe_syscall_root+0x84) :| +*begin 0x80000001 -1038 0.960 __ipipe_notify_syscall+0x34 (__ipipe_syscall_root+0x84) :| +*end 0x80000001 -1037 0.680 __ipipe_notify_syscall+0x94 (__ipipe_syscall_root+0x84) : +*func -1037 0.760 ipipe_syscall_hook+0x10 (__ipipe_notify_syscall+0xa4) : +*func -1036+ 1.280 hisyscall_event+0x14 (ipipe_syscall_hook+0x44) : +*func -1035 0.720 __rt_task_wait_period+0x14 (hisyscall_event+0x17c) : +*func -1034+ 1.040 rt_task_wait_period+0x10 (__rt_task_wait_period+0x24) : +*func -1033 0.680 xnpod_wait_thread_period+0x14 (rt_task_wait_period+0x48) :| +*begin 0x80000000 -1032+ 1.520 xnpod_wait_thread_period+0x3c (rt_task_wait_period+0x48) :| #*func -1031+ 1.200 xnpod_suspend_thread+0x14 (xnpod_wait_thread_period+0x144) :| #*func -1030 0.840 __xnpod_schedule+0x14 (xnpod_suspend_thread+0x444) :| #*[ 3238] samplin 99 -1029 1.000 __xnpod_schedule+0x134 (xnpod_suspend_thread+0x444) :| #*func -1028+ 1.840 xnsched_pick_next+0x10 (__xnpod_schedule+0x160) :| #*func -1026+ 1.800 check_and_switch_context+0x14 (__xnpod_schedule+0x3ec) :| #*[ 66] mmcqd/0 -1 -1024+ 2.240 __xnpod_schedule+0x45c (xnintr_clock_handler+0x29c) :| #func -1022 0.880 __ipipe_do_sync_pipeline+0x10 (__ipipe_dispatch_irq+0x28c) :| #end 0x00000053 -1021 0.640 __ipipe_grab_irq+0x94 (omap3_intc_handle_irq+0x70) :| #func -1020+ 1.400 __ipipe_exit_irq+0x10 (__ipipe_grab_irq+0x9c) :| #func -1019 0.800 __ipipe_check_root_interruptible+0x10 (__irq_svc+0x5c) :| #func -1018 0.600 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_fast_svc_irq_exit+0x4) :| #end 0x90000000 -1018+ 2.240 __ipipe_fast_svc_irq_exit+0x18 (__ipipe_trace+0x408) : #func -1015+ 6.040 _memcpy_toio+0x10 (edma_write_slot+0x4c) : #func -1009+ 2.240 edma_link+0x10 (edma_execute+0xa4) : #func -1007+ 2.600 edma_start+0x10 (edma_execute+0xb8) : #func -1004 0.840 _raw_spin_unlock_irqrestore+0x10 (edma_issue_pending+0x88) : #func -1004 1.000 ipipe_unstall_root+0x10 (_raw_spin_unlock_irqrestore+0x28) :| #begin 0x80000000 -1003 0.960 ipipe_unstall_root+0x2c (_raw_spin_unlock_irqrestore+0x28) :| #func -1002 0.800 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -1001+ 1.840 ipipe_unstall_root+0x64 (_raw_spin_unlock_irqrestore+0x28) : +func -999+ 3.800 omap_hsmmc_start_command+0x10 (omap_hsmmc_request+0x428) : +func -995 0.680 _raw_spin_lock_irq+0x10 (mmc_queue_thread+0x4c) :| +begin 0x80000001 -995+ 1.040 _raw_spin_lock_irq+0x30 (mmc_queue_thread+0x4c) :| #end 0x80000001 -993+ 2.320 _raw_spin_lock_irq+0x50 (mmc_queue_thread+0x4c) :| #begin 0x90000000 -991+ 1.400 __irq_svc+0x44 (do_raw_spin_lock+0xe4) :| #func -990+ 1.040 omap3_intc_handle_irq+0x10 (__irq_svc+0x58) :| #func -989 0.720 irq_find_mapping+0x10 (omap3_intc_handle_irq+0x64) :| #func -988+ 1.120 irq_domain_legacy_revmap+0x10 (irq_find_mapping+0x5c) :| #func -987 0.640 __ipipe_grab_irq+0x10 (omap3_intc_handle_irq+0x70) :| #begin 0x00000050 -986 0.960 __ipipe_grab_irq+0x24 (omap3_intc_handle_irq+0x70) :| #func -985 0.680 __ipipe_dispatch_irq+0x10 (__ipipe_grab_irq+0x8c) :| #func -985 1.000 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x4c) :| #func -984+ 2.200 irq_to_desc+0x10 (__ipipe_dispatch_irq+0x2ac) :| #func -981 0.680 __ipipe_ack_irq+0x10 (__ipipe_dispatch_irq+0xd8) :| #func -981 0.640 __ipipe_ack_level_irq+0x10 (__ipipe_ack_irq+0x1c) :| #func -980 0.920 omap_mask_ack_irq+0x10 (__ipipe_ack_level_irq+0x4c) :| #func -979+ 1.240 irq_gc_mask_disable_reg+0x10 (omap_mask_ack_irq+0x18) :| #func -978+ 2.280 __ipipe_set_irq_pending+0x10 (__ipipe_dispatch_irq+0x24c) :| #func -976 0.800 __ipipe_do_sync_pipeline+0x10 (__ipipe_dispatch_irq+0x28c) :| #end 0x00000050 -975 0.600 __ipipe_grab_irq+0x94 (omap3_intc_handle_irq+0x70) :| #func -974+ 1.360 __ipipe_exit_irq+0x10 (__ipipe_grab_irq+0x9c) :| #func -973 0.800 __ipipe_check_root_interruptible+0x10 (__irq_svc+0x5c) :| #func -972 0.600 __ipipe_bugon_irqs_enabled+0x10 (__ipipe_fast_svc_irq_exit+0x4) :| #end 0x90000000 -971+ 1.400 __ipipe_fast_svc_irq_exit+0x18 (do_raw_spin_lock+0xe4) : #func -970 0.680 blk_fetch_request+0x10 (mmc_queue_thread+0x60) : #func -969+ 1.160 blk_peek_request+0x10 (blk_fetch_request+0x18) : #func -968+ 1.760 cfq_dispatch_requests+0x14 (blk_peek_request+0x1e0) : #func -966 0.800 _raw_spin_unlock_irq+0x10 (mmc_queue_thread+0x74) : #func -966+ 1.040 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -965+ 1.080 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -964 0.800 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +func -963+ 2.240 __ipipe_do_sync_stage+0x10 (ipipe_unstall_root+0x50) :| #end 0x80000000 -961+ 1.480 __ipipe_do_sync_stage+0x1ac (ipipe_unstall_root+0x50) : #func -959+ 1.480 __ipipe_do_IRQ+0x10 (__ipipe_do_sync_stage+0x214) : #func -958 0.720 handle_IRQ+0x10 (__ipipe_do_IRQ+0x1c) : #func -957 0.760 irq_enter+0x10 (handle_IRQ+0x28) : #func -956 0.960 rcu_irq_enter+0x10 (irq_enter+0x18) :| #begin 0x80000001 -955+ 1.040 rcu_irq_enter+0x2c (irq_enter+0x18) :| #end 0x80000001 -954+ 1.080 rcu_irq_enter+0x4c (irq_enter+0x18) : #func -953+ 1.400 ipipe_root_only+0x10 (irq_enter+0x58) : #func -952 0.640 generic_handle_irq+0x10 (handle_IRQ+0x70) : #func -951+ 1.200 irq_to_desc+0x10 (generic_handle_irq+0x1c) : #func -950 0.640 handle_level_irq+0x10 (generic_handle_irq+0x30) : #func -949+ 2.080 _raw_spin_lock+0x10 (handle_level_irq+0x24) : #func -947+ 1.040 handle_irq_event+0x10 (handle_level_irq+0xa4) : #func -946+ 1.160 _raw_spin_unlock+0x10 (handle_irq_event+0x40) : #func -945+ 1.240 handle_irq_event_percpu+0x14 (handle_irq_event+0x4c) : #func -944+ 3.480 omap_hsmmc_irq+0x10 (handle_irq_event_percpu+0x70) : #func -940 0.960 add_interrupt_randomness+0x14 (handle_irq_event_percpu+0x264) : #func -939+ 2.640 read_current_timer+0x10 (add_interrupt_randomness+0x38) : #func -937+ 1.520 note_interrupt+0x10 (handle_irq_event_percpu+0x284) : #func -935 0.840 _raw_spin_lock+0x10 (handle_irq_event+0x58) : #func -934+ 1.040 unmask_irq+0x10 (handle_level_irq+0xcc) :| #begin 0x80000001 -933 0.720 unmask_irq+0x40 (handle_level_irq+0xcc) :| #func -932 1.000 irq_gc_unmask_enable_reg+0x10 (unmask_irq+0x50) :| #end 0x80000001 -931 1.000 unmask_irq+0x6c (handle_level_irq+0xcc) : #func -930+ 1.120 _raw_spin_unlock+0x10 (handle_level_irq+0xd4) : #func -929 0.960 irq_exit+0x10 (handle_IRQ+0x74) : #func -928 1.000 ipipe_root_only+0x10 (irq_exit+0x18) : #func -927+ 1.200 idle_cpu+0x10 (irq_exit+0x5c) : #func -926+ 1.040 rcu_irq_exit+0x10 (irq_exit+0x98) :| #begin 0x80000001 -925+ 1.400 rcu_irq_exit+0x2c (irq_exit+0x98) :| #end 0x80000001 -924 0.920 rcu_irq_exit+0x4c (irq_exit+0x98) :| #begin 0x80000000 -923+ 1.280 __ipipe_do_sync_stage+0x22c (ipipe_unstall_root+0x50) :| +end 0x80000000 -921 0.760 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -921 1.000 mmc_blk_issue_rq+0x14 (mmc_queue_thread+0xa8) : +func -920 0.840 dev_get_drvdata+0x10 (mmc_blk_issue_rq+0x4c) : +func -919 1.000 mmc_blk_issue_rw_rq+0x14 (mmc_blk_issue_rq+0x434) : +func -918 0.960 mmc_start_req+0x10 (mmc_blk_issue_rw_rq+0xb8) : +func -917+ 1.040 mmc_wait_for_req_done+0x10 (mmc_start_req+0x60) : +func -916 0.960 wait_for_completion+0x10 (mmc_wait_for_req_done+0x2c) : +func -915 0.640 wait_for_common+0x14 (wait_for_completion+0x20) : +func -914+ 1.040 ipipe_root_only+0x10 (wait_for_common+0x2c) : +func -913 0.800 _cond_resched+0x10 (wait_for_common+0x30) : +func -912+ 1.040 _raw_spin_lock_irq+0x10 (wait_for_common+0x38) :| +begin 0x80000001 -911 0.680 _raw_spin_lock_irq+0x30 (wait_for_common+0x38) :| #end 0x80000001 -911+ 2.640 _raw_spin_lock_irq+0x50 (wait_for_common+0x38) : #func -908 0.800 _raw_spin_unlock_irq+0x10 (wait_for_common+0x134) : #func -907 0.640 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -907+ 1.320 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -905 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -905+ 1.120 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) : +func -903 0.680 schedule_timeout+0x14 (wait_for_common+0x13c) : +func -903+ 1.320 schedule+0x10 (schedule_timeout+0x2c) : +func -901 0.680 __schedule+0x14 (schedule+0x94) : +func -901 0.680 rcu_sched_qs+0x10 (__schedule+0x34) :| +begin 0x80000001 -900+ 1.040 rcu_sched_qs+0x2c (__schedule+0x34) :| #end 0x80000001 -899+ 1.280 rcu_sched_qs+0x4c (__schedule+0x34) : #func -898 0.680 ipipe_unstall_root+0x10 (rcu_sched_qs+0xd4) :| #begin 0x80000000 -897+ 1.080 ipipe_unstall_root+0x2c (rcu_sched_qs+0xd4) :| #func -896 0.720 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -895+ 1.400 ipipe_unstall_root+0x64 (rcu_sched_qs+0xd4) : +func -894 0.800 ipipe_root_only+0x10 (__schedule+0x48) : +func -893 0.680 _raw_spin_lock_irq+0x10 (__schedule+0x9c) :| +begin 0x80000001 -892 1.000 _raw_spin_lock_irq+0x30 (__schedule+0x9c) :| #end 0x80000001 -891+ 1.840 _raw_spin_lock_irq+0x50 (__schedule+0x9c) : #func -890 1.000 deactivate_task+0x10 (__schedule+0x560) : #func -889+ 1.200 dequeue_task+0x10 (deactivate_task+0x38) : #func -887+ 1.800 update_rq_clock+0x10 (dequeue_task+0x28) : #func -886+ 1.480 dequeue_task_fair+0x14 (dequeue_task+0xb8) : #func -884+ 1.400 update_curr+0x14 (dequeue_task_fair+0x40) : #func -883+ 1.840 update_min_vruntime+0x10 (update_curr+0xc0) : #func -881+ 2.640 cpuacct_charge+0x10 (update_curr+0x12c) : #func -878+ 1.360 clear_buddies+0x10 (dequeue_task_fair+0xa4) : #func -877+ 1.040 account_entity_dequeue+0x10 (dequeue_task_fair+0xcc) : #func -876+ 1.480 update_min_vruntime+0x10 (dequeue_task_fair+0xf4) : #func -874+ 1.600 update_cfs_shares+0x10 (dequeue_task_fair+0xfc) : #func -873+ 1.080 put_prev_task_fair+0x10 (__schedule+0x1f8) : #func -872+ 1.240 pick_next_task_fair+0x10 (__schedule+0x220) : #func -870 0.840 __pick_first_entity+0x10 (pick_next_task_fair+0x2c) : #func -870 0.920 clear_buddies+0x10 (pick_next_task_fair+0xb0) : #func -869 1.000 set_next_entity+0x10 (pick_next_task_fair+0xbc) : #func -868+ 1.840 update_stats_wait_end+0x10 (set_next_entity+0x2c) : #func -866+ 2.880 __dequeue_entity+0x10 (set_next_entity+0x38) : #func -863 0.800 __pick_first_entity+0x10 (pick_next_task_fair+0x2c) : #func -862 0.640 clear_buddies+0x10 (pick_next_task_fair+0xb0) : #func -862 1.000 set_next_entity+0x10 (pick_next_task_fair+0xbc) : #func -861+ 1.240 update_stats_wait_end+0x10 (set_next_entity+0x2c) : #func -859+ 1.440 __dequeue_entity+0x10 (set_next_entity+0x38) :| #begin 0x80000001 -858 1.000 __schedule+0x274 (schedule+0x94) :| #end 0x80000001 -857+ 3.200 __schedule+0x298 (schedule+0x94) :| #begin 0x80000000 -854+ 1.440 __schedule+0x464 (schedule+0x94) :| #func -852 0.840 __switch_mm_inner+0x10 (__schedule+0x4c4) :| #func -851+ 2.880 check_and_switch_context+0x14 (__switch_mm_inner+0x50) :| #func -848+ 1.520 __ipipe_switch_to_notifier_call_chain+0x10 (__switch_to+0x2c) :| #func -847 0.720 atomic_notifier_call_chain+0x14 (__ipipe_switch_to_notifier_call_chain+0x6c) :| #func -846 0.680 __atomic_notifier_call_chain+0x14 (atomic_notifier_call_chain+0x28) :| #func -846+ 1.080 notifier_call_chain+0x10 (__atomic_notifier_call_chain+0x28) :| #func -844+ 1.440 vfp_notifier+0x10 (notifier_call_chain+0x48) :| #func -843+ 1.760 thumbee_notifier+0x10 (notifier_call_chain+0x48) :| #func -841+ 1.680 __ipipe_restore_root_nosync+0x10 (__ipipe_switch_to_notifier_call_chain+0x7c) :| #func -840 0.760 __ipipe_switch_tail+0x10 (__schedule+0x504) :| #end 0x80000000 -839+ 1.040 __ipipe_switch_tail+0x70 (__schedule+0x504) : #func -838+ 1.040 finish_task_switch.constprop.72+0x10 (__schedule+0x514) : #func -837 0.800 _raw_spin_unlock_irq+0x10 (finish_task_switch.constprop.72+0x60) : #func -836 1.000 ipipe_unstall_root+0x10 (_raw_spin_unlock_irq+0x1c) :| #begin 0x80000000 -835 0.840 ipipe_unstall_root+0x2c (_raw_spin_unlock_irq+0x1c) :| #func -834+ 1.080 ipipe_root_only+0x10 (ipipe_unstall_root+0x30) :| +end 0x80000000 -833+ 2.640 ipipe_unstall_root+0x64 (_raw_spin_unlock_irq+0x1c) :| +begin 0x80000000 -830+ 1.240 do_work_pending+0x144 (work_pending+0xc) :| +func -829 0.960 __ipipe_bugon_irqs_enabled+0x10 (no_work_pending+0x4) :| +end 0x90000000 -828+ 7.360 no_work_pending+0x18 (<b6e35592>) :| +begin 0x90000000 -821+ 1.600 __und_usr+0x20 (<b6e2138c>) :| +func -819+ 4.600 __ipipe_notify_trap+0x14 (__und_usr+0x58) :| +func -815+ 1.080 __ipipe_check_root+0x10 (ret_from_exception+0x8) :| +func -814 0.600 __ipipe_bugon_irqs_enabled+0x10 (no_work_pending+0x4) :| +end 0x90000000 -813+ 2.960 no_work_pending+0x18 (<b6e2138a>) :| +begin 0x90000000 -810+ 1.800 vector_swi+0x3c (<b69ac008>) : +func -808+ 1.240 __ipipe_syscall_root+0x10 (vector_swi+0x7c) : +func -807 0.680 sys_gettimeofday+0x14 (ret_fast_syscall+0x0) : +func -806 0.720 do_gettimeofday+0x14 (sys_gettimeofday+0x2c) : +func -806+ 4.320 getnstimeofday+0x10 (do_gettimeofday+0x24) :| +func -801 0.640 __ipipe_bugon_irqs_enabled+0x10 (ret_fast_syscall+0x14) :| +end 0x90000000 -801+ 2.920 ret_fast_syscall+0x2c (<b69ac00c>) :| +begin 0x90000000 -798+ 1.440 vector_swi+0x3c (<b69ac008>) : +func -796 0.720 __ipipe_syscall_root+0x10 (vector_swi+0x7c) : +func -796 0.640 sys_gettimeofday+0x14 (ret_fast_syscall+0x0) : +func -795 0.880 do_gettimeofday+0x14 (sys_gettimeofday+0x2c) : +func -794+ 1.280 getnstimeofday+0x10 (do_gettimeofday+0x24) :| +func -793 0.600 __ipipe_bugon_irqs_enabled+0x10 (ret_fast_syscall+0x14) :| +end 0x90000000 -792+ 5.240 ret_fast_syscall+0x2c (<b69ac00c>) :| +begin 0x90000000 -787+ 1.120 vector_swi+0x3c (<b69d2f00>) : +func -786+ 1.080 __ipipe_syscall_root+0x10 (vector_swi+0x7c) : +func -785+ 3.120 sys_select+0x14 (ret_fast_syscall+0x0) : +func -782+ 1.320 poll_select_set_timeout+0x14 (sys_select+0xb8) : +func -780+ 1.920 ktime_get_ts+0x10 (poll_select_set_timeout+0x40) : +func -778+ 1.160 timespec_add_safe+0x18 (poll_select_set_timeout+0x54) : +func -777+ 2.080 set_normalized_timespec+0x10 (timespec_add_safe+0x58) : +func -775+ 5.040 core_sys_select+0x14 (sys_select+0xe4) : +func -770+ 1.920 do_select+0x14 (core_sys_select+0x234) : +func -768+ 1.880 poll_initwait+0x10 (do_select+0x11c) : +func -766+ 1.400 select_estimate_accuracy+0x14 (do_select+0x180) : +func -765 0.960 ktime_get_ts+0x10 (select_estimate_accuracy+0xd0) : +func -764+ 1.120 set_normalized_timespec+0x10 (select_estimate_accuracy+0xf4) : +func -763+ 4.040 task_nice+0x10 (select_estimate_accuracy+0x44) : +func -759+ 1.240 poll_schedule_timeout+0x10 (do_select+0x458) : +func -757+ 1.240 schedule_hrtimeout_range+0x10 (poll_schedule_timeout+0x44) : +func -756+ 1.960 schedule_hrtimeout_range_clock+0x14 (schedule_hrtimeout_range+0x1c) : +func -754+ 2.320 hrtimer_init+0x10 (schedule_hrtimeout_range_clock+0x70) : +func -752+ 1.080 ktime_add_safe+0x10 (schedule_hrtimeout_range_clock+0x8c) : +func -751 1.000 hrtimer_start_range_ns+0x14 (schedule_hrtimeout_range_clock+0xbc) : +func -750 0.680 __hrtimer_start_range_ns+0x14 (hrtimer_start_range_ns+0x34) : +func -749 0.680 _raw_spin_lock_irqsave+0x10 (__hrtimer_start_range_ns+0x34) :| +begin 0x80000001 -749 0.720 _raw_spin_lock_irqsave+0x30 (__hrtimer_start_range_ns+0x34) :| #end 0x80000001 -748+ 1.840 _raw_spin_loc

Your Answer

Name:
Reply:

All Answers

Answer by 3 months ago
You mean thumb2? Did you enable the workaround for buggy gas? I also get 50us at 1kHz, I only get 40us at 10kHz.
Answer by 3 months ago
Yes, thumb2, and yes, the buggy gas workaround was enabled (by default when selecting a thumb2 build). Googling the resulting errors brought up some threads about iMX6 kernel builds failing the same way, which is where I got "too big for some jump/branch instructions" which I also translate as "beyond my currently capability to fix with any expectation that I'm not introducing other issues". :) Good, it sounds like we're seeing basically the same numbers. I can live with the 50 uS latency, which is already significantly better than I was expecting since I hadn't done testing for a while. -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 261 bytes Desc: OpenPGP digital signature URL: <http://www.xenomai.org/pipermail/xenomai/attachments/20140112/3bf13f7c/attachment.sig>
Answer by 3 months ago
The .config you attached to the mail I am answering has CONFIG_PREEMPT enabled. You may want to select CONFIG_PREEMPT_NONE. I also do not really understand the trace you have attached. Are you running other real-time tasks than the latency test? Because to get accurate results, you should run the latency test without any other programs using xenomai.
Answer by 3 months ago
OK, thanks for the clarification. I show CONFIG_PREEMPT was not set, but CONFIG_PREEMPT_VOLUNTARY was: # CONFIG_PREEMPT_NONE is not set CONFIG_PREEMPT_VOLUNTARY=y # CONFIG_PREEMPT is not set I can select CONFIG_PREEMPT_NONE and re-test. Yes, my primary load is running LinuxCNC, which uses Xenomai. I'll build a new kernel and post a new trace, this time without running any other programs that use Xenomai. Thanks for all the advice and help! -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 261 bytes Desc: OpenPGP digital signature URL: <http://www.xenomai.org/pipermail/xenomai/attachments/20140112/bbf3cd16/attachment.sig>