Re: [PATCH v6] tracing: add additional marks to signal very large time

From: Steven Rostedt
Date: Wed Dec 03 2014 - 04:15:43 EST


On Mon, 24 Nov 2014 09:34:19 +0900
byungchul.park@xxxxxxx wrote:

> From: Byungchul Park <byungchul.park@xxxxxxx>
>
> Currently, function graph tracer prints "!" or "+" just before
> function execution time to signal a function overhead, depending
> on the time. And some tracers tracing latency also print "!" or
> "+" just after time to signal overhead, depending on the interval
> between events. Even it is usually enough to do that, we sometimes
> need to be signaled for bigger execution time than 100 micro seconds.
>
> For example, I used function graph tracer to detect if there is
> any case that exit_mm() takes too much time. I did following steps
> in /sys/kernel/debug/tracing. It was easier to detect very big
> excution time with patched kernel than with original kernel.
>
> $ echo exit_mm > set_graph_function
> $ echo function_graph > current_tracer
> $ echo > trace
> $ cat trace_pipe > $LOGFILE
> ... (do something and terminate logging)
> $ grep "\\$" $LOGFILE
> 3) $ 22082032 us | } /* kernel_map_pages */
> 3) $ 22082040 us | } /* free_pages_prepare */
> 3) $ 22082113 us | } /* free_hot_cold_page */
> 3) $ 22083455 us | } /* free_hot_cold_page_list */
> 3) $ 22083895 us | } /* release_pages */
> 3) $ 22177873 us | } /* free_pages_and_swap_cache */
> 3) $ 22178929 us | } /* unmap_single_vma */
> 3) $ 22198885 us | } /* unmap_vmas */
> 3) $ 22206949 us | } /* exit_mmap */
> 3) $ 22207659 us | } /* mmput */
> 3) $ 22207793 us | } /* exit_mm */
>
> And then, it was easy to find out that a schedule-out occured by
> sub_preempt_count() within kernel_map_pages().
>
> To detect very large function exection time caused by either problematic
> function implementation or scheduling issues, this patch can be useful.
>
> Signed-off-by: Byungchul Park <byungchul.park@xxxxxxx>

Looks good!

Thanks,

-- Steve
--
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/