Why does the timestamp in ftrace output jump around?

Solution Verified - Updated -

Issue

  • Why does the timestamp in ftrace output jump around?

Example:

    15d.... 84936.642635: funcgraph_entry:        0.498 us   |     native_read_cr0();
    15d.... 84936.642636: funcgraph_entry:        0.279 us   |     native_write_cr0();
--> 13d.... 84936.720054: sched_wakeup:         25221:?:? +  25222:39:? java [015] Success
    13d.... 84936.721371: sched_wakeup:         25221:?:? +  25222:39:? java [015] Success
    14d.... 84936.735276: sched_wakeup:         25210:?:? +  25222:39:? java [015] Success
    13d.... 84936.749354: funcgraph_exit:         1.171 us   |                   }
    13d.... 84936.749354: funcgraph_entry:                   |                   __enqueue_rt_entity() {
    13d.... 84936.749354: funcgraph_entry:                   |                     cpupri_set() {
--> 13d.... 84936.642664: funcgraph_entry:        0.533 us   |                       _spin_lock_irqsave();
    13d.... 84936.642664: funcgraph_entry:        0.237 us   |                       _spin_unlock_irqrestore();

Environment

Red Hat Enterprise Linux (RHEL) 6
Red Hat Enterprise MRG Realtime 1.3
Red Hat Enterprise MRG Realtime 2.0

Subscriber exclusive content

A Red Hat subscription provides unlimited access to our knowledgebase of over 48,000 articles and solutions.

Current Customers and Partners

Log in for full access

Log In
Close

Welcome! Check out the Getting Started with Red Hat page for quick tours and guides for common tasks.