TipsAndTricks/InvestigatingBuildTime

From Yocto Project
Revision as of 20:45, 15 November 2016 by Leonardo Sandoval (talk | contribs)
Jump to navigationJump to search

Draft: Investigating Build Time

(Placeholder. Demonstrate use of buildstats and pybootchartgui)

Current status: The intention is to use the scripts under scripts/contrib/bb-perf to parse buildstat data and produce useful plots.


The buildstats data produced by the class with the same name provides process statistics for every recipe task. This data can offer insight of the time spent by the builder (bitbake) when constructing a particular target at process level. This article focus more on profiling than optimization, the former being the base for the latter.

Setup

 $ cd poky
 $ git checkout -b morty origin/morty
 $ . oe-init-build-env
 $ bitbake world

Buildstats

buildstats.bbclass stores mainly two set of process' stats: time and IO stats. For the moment, we are currently focusing on the following time data:

  • /proc/[pid]/stat: utime, stime
  • /proc/[pid]/stat: cutime, cstime
  • python resource module: rusage ru_utime, rusage ru_stime
  • python resource module: Child rusage ru_utime, Child rusage ru_stime

and the IO stats:

  • /proc/[pid]/io: IO rchar, IO wchar
  • /proc/[pid]/io: IO read_bytes, IO write_bytes

With this data, the following script (once the bitbake world command has finished) is used to either plot the top N recipes-task stat values

$ ../scripts/contrib/bb-perf/buildstats-plot.sh -s <BUILDSTATS> -N $N | gnuplot -p

or sum stats values per task for all (world) recipes

$ ../scripts/contrib/bb-perf/buildstats-plot.sh -s <BUILDSTATS> -S | gnuplot -p

The former produces a more granular plot and second a more general idea where the type is spent per task set.

Setup

 curl -sSf | bash

Results

Utime.t.pngUtime.ts.png Stime.t.png Stime.ts.png Cutime.t.png Cutime.ts.png Cstime.t.png Cstime.ts.png IO-wchar.t.png IO-wchar.ts.png IO-write bytes.t.png IO-write bytes.ts.png IO-syscr.t.png IO-syscr.ts.png IO-read bytes.t.png IO-read bytes.ts.png IO-rchar.t.png IO-rchar.ts.png IO-syscw.t.png IO-syscw.ts.png IO-cancelled write bytes.t.png IO-cancelled write bytes.ts.png Rusage-ru utime.t.png Rusage-ru utime.ts.png Rusage-ru stime.t.png Rusage-ru stime.ts.png Rusage-ru maxrss.t.png Rusage-ru maxrss.ts.png Rusage-ru minflt.t.png Rusage-ru minflt.ts.png Rusage-ru majflt.t.png Rusage-ru majflt.ts.png Rusage-ru inblock.t.png Rusage-ru inblock.ts.png Rusage-ru oublock.t.png Rusage-ru oublock.ts.png Rusage-ru nvcsw.t.png Rusage-ru nvcsw.ts.png Rusage-ru nivcsw.t.png Rusage-ru nivcsw.ts.png Child-rusage-ru utime.t.png Child-rusage-ru utime.ts.png Child-rusage-ru stime.t.png Child-rusage-ru stime.ts.png Child-rusage-ru maxrss.t.png Child-rusage-ru maxrss.ts.png Child-rusage-ru minflt.t.png Child-rusage-ru minflt.ts.png Child-rusage-ru majflt.t.png Child-rusage-ru majflt.ts.png Child-rusage-ru inblock.t.png Child-rusage-ru inblock.ts.png Child-rusage-ru oublock.t.png Child-rusage-ru oublock.ts.png Child-rusage-ru nvcsw.t.png Child-rusage-ru nvcsw.ts.png Child-rusage-ru nivcsw.t.png Child-rusage-ru nivcsw.ts.png