szaydel
4/6/2018 - 9:04 PM

Observe Golang Syscall and Runtime function activity

Snippets for various observations of Go-based programs. Golang's runtime will have a runtime.something in the probefunc string, and most of the stuff here will in one way or another be looking at that stuff.

go-runtime-and-syscall-time.go
content_copyfile_download
dtrace -qn '
  unsigned long c, sc, last_ts;
  BEGIN {
    start = timestamp;
    last_ts = start;

  }
  syscall:::entry /pid==$target/ {
    sc++;
  }

  pid$target:libc.so.1:nanosleep:entry {
    self->sleep = timestamp;
  }

  pid$target:libc.so.1:nanosleep:return /self->sleep/ {
    @slp = sum(timestamp - self->sleep);
    self->sleep = 0;
  }
  pid$target::runtime\.*:entry {c++}
  tick-10sec {
    this->now = timestamp;
    this->delta = (this->now - last_ts)/1000000000;
    last_ts = this->now;
    @runtCt["runtime.*"] = sum(c);
    @runtq["runtime.*"] = quantize(c/this->delta);
    @syscallCt["syscall"] = sum(sc);
    @syscallq["syscall"] = quantize(sc/this->delta == 0 ? 1 : sc/this->delta);
    c = 0; sc = 0;
  }
  END {
    this->now = timestamp;
    normalize(@slp, (this->now-start)/1000000);
    normalize(@runtCt, (this->now-start)/1000000000);
    normalize(@syscallCt, (this->now-start)/1000000000);
    printa("Avg. Call Count: %s/sec %@d | ", @runtCt);
    printa("%s/sec %@d\n", @syscallCt);
    printf("Total Runtime(sec): %d | ", (this->now - start)/1000000000);
    printa("avg. sleep time/sec(uS): %@d\n", @slp);
  }' -p `pgrep metricsd`