global then;
global deltas;

global start;

function print_ts(str) {
  now = gettimeofday_ns() / (1000*1000)

  delta = (now - start)

  printf("%3d.%03d %s\n",
         (delta / 1000), (delta % 1000), str);
}


probe begin {
   printf("Begin\n");
   then = 0;
  start = gettimeofday_ns() / (1000*1000);
  print_ts("Start");

}


probe process("/home/berrange/usr/qemu-git/bin/qemu-system-x86_64").function("qemu_savevm_state_begin") {
   then = gettimeofday_ns() / (1000*1000);
   print_ts("> Begin");   
}

probe process("/home/berrange/usr/qemu-git/bin/qemu-system-x86_64").function("qemu_savevm_state_begin").return {
   now = gettimeofday_ns() / (1000*1000);
   if (then != 0) {
     delta = now - then;
     deltas <<< delta;
     print_ts(sprintf("< Begin %3d.%03d",
         (delta / 1000), (delta % 1000)));
   }
}

probe process("/home/berrange/usr/qemu-git/bin/qemu-system-x86_64").function("qemu_savevm_state_iterate") {
   then = gettimeofday_ns() / (1000*1000);
   print_ts("> Iterate");   
}

probe process("/home/berrange/usr/qemu-git/bin/qemu-system-x86_64").function("qemu_savevm_state_iterate").return {
   now = gettimeofday_ns() / (1000*1000);
   if (then != 0) {
     delta = now - then;
     deltas <<< delta;
     print_ts(sprintf("< Iterate %3d.%03d",
         (delta / 1000), (delta % 1000)));
   }
}

probe process("/home/berrange/usr/qemu-git/bin/qemu-system-x86_64").function("qemu_savevm_state_complete") {
   then = gettimeofday_ns() / (1000*1000);
   print_ts("> Complete");   
}

probe process("/home/berrange/usr/qemu-git/bin/qemu-system-x86_64").function("qemu_savevm_state_complete").return {
   now = gettimeofday_ns() / (1000*1000);
   if (then != 0) {
     delta = now - then;
     deltas <<< delta;
     print_ts(sprintf("< Complete %3d.%03d",
         (delta / 1000), (delta % 1000)));
   }
}


probe end {
   printf ("avg %d = sum %d / count %d; min %d max %d\n",
           @avg(deltas), @sum(deltas), @count(deltas), @min(deltas), @max(deltas));
   print (@hist_log(deltas));
}