On Tue, Nov 30, 2010 at 11:40:36PM +0100, Juan Quintela wrote: > Stefan Hajnoczi <stefa...@linux.vnet.ibm.com> wrote: > > On Mon, Nov 29, 2010 at 08:00:18PM -0600, Anthony Liguori wrote: > >> Yeah, all of this should be done via tracing. Maybe Stefan can make > >> some suggestions. > > > > Here is an example of how to record savevm timestamps using tracing. > > Actually the timestamp is recorded automatically when a trace event > > fires. > > > > Add these to the trace-events file: > > savevm_start(void) "" > > savevm_stop(unsigned int section_id) "section_id %u" > > > > Then use trace_savevm_start() instead of START_SAVEVM_CLOCK() and > > trace_savevm_stop() instead of STOP_SAVEVM_CLOCK() in savevm.c. Also > > #include "trace.h". > > > > All the macros and inline timestamp analysis can be removed from > > savevm.c. > > > > ./configure --trace-backend=simple [...] > > make > > > > After running savevm look for the trace-<pid> file that QEMU produces in > > its current working directory. You can pretty-print it like this: > > ./simpletrace.py trace-events trace-<pid> > > > > The second field in the simpletrace.py output is the time delta (in > > microseconds) since the last trace event. So you can easily see how > > long start->stop took. > > > > For more info see docs/tracing.txt. You might prefer to use SystemTap > > (./configure --trace-backend=dtrace) so you can write stap scripts to do > > more powerful analysis. > > Thanks. > > Searching for guru, I basically want to only print the values when the > difference is bigger that some values (number of calls is really big, I > need to learn how to script the analisys).
You can use awk(1) on the simpletrace.py output: $1 ~ /savevm_stop/ { /* Print savevm_stop line when >100 ms duration */ if ($2 > 100000) { printf("%s times_missing=%u\n", $0, times_missing++); } } Or you can use --trace-backend=dtrace and write SystemTap scripts: http://sourceware.org/systemtap/SystemTap_Beginners_Guide/ http://sourceware.org/systemtap/langref/ Stefan