Working with build statistics

The build system can collect build information per task and image. The data may be used to identify areas of optimization of build times and bottlenecks, especially when new recipes are added to the system. This recipe will explain how the build statistics work.

How to do it...

To enable the collection of statistics, your project needs to inherit the buildstats class by adding it to USER_CLASSES in your conf/local.conf file. By default, the fsl-community-bsp build project is configured to enable them:

USER_CLASSES ?= "buildstats"  

You can configure the location of these statistics with the BUILDSTATS_BASE variable, and by default it is set to the buildstats folder in the tmp directory under the build directory (tmp/buildstats).

The buildstats folder contains a folder per image with the build stats under a timestamp folder. Under it will be a sub-directory per package in your built image, and a build_stats file that contains:

• Host system information
• Root filesystem location and size
• Build time
• Average CPU usage

How it works...

The accuracy of the data depends on the download directory, DL_DIR, and the shared state cache directory, SSTATE_DIR, existing on the same partition or volume, so you may need to configure them accordingly if you are planning to use the build data.

An example build-stats file looks like the following:

Host Info: Linux langabe 4.10.0-30-generic #34~16.04.1-Ubuntu SMP Wed Aug 2 02:13:56 UTC 2017 x86_64 x86_64 
Build Started: 1502529685.16                                                     
Uncompressed Rootfs size: 93M   /opt/yocto/fsl-community-bsp/wandboard/tmp/work/wandboard-poky-linux-gnueabi/core-image-minimal/1.0-r0/rootfs 
Elapsed time: 101.87 seconds                                                     
CPU usage: 47.8% 

Inside each package, we have a list of tasks; for example, for ncurses-6.0+20161126-r0, we have the following tasks:

• do_compile
• do_fetch
• do_package
• do_package_write_rpm
• do_populate_lic
• do_rm_work
• do_configure
• do_install
• do_packagedata
• do_package_qa
• do_patch
• do_prepare_recipe_sysroot
• do_populate_sysroot
• do_unpack

Each one of them contains the following:

• Build time
• CPU usage
• Disk stats

The information is displayed as follows:

Event: TaskStarted                                                               
Started: 1502541082.15                                                           
ncurses-6.0+20161126-r0: do_compile                                              
Elapsed time: 35.37 seconds                                                      
utime: 31                                                                        
stime: 2                                                                         
cutime: 7790                                                                     
cstime: 1138                                                                     
IO rchar: 778886123                                                              
IO read_bytes: 3354624                                                           
IO wchar: 79063307                                                               
IO cancelled_write_bytes: 1507328                                                
IO syscr: 150688                                                                 
IO write_bytes: 26726400                                                         
IO syscw: 31565                                                                  
rusage ru_utime: 0.312                                                           
rusage ru_stime: 0.027999999999999997                                            
rusage ru_maxrss: 78268                                                          
rusage ru_minflt: 5050                                                           
rusage ru_majflt: 0                                                              
rusage ru_inblock: 0                                                             
rusage ru_oublock: 1184                                                          
rusage ru_nvcsw: 705                                                             
rusage ru_nivcsw: 126                                                            
Child rusage ru_utime: 77.908                                                    
Child rusage ru_stime: 11.388                                                    
Child rusage ru_maxrss: 76284                                                    
Child rusage ru_minflt: 2995484                                                  
Child rusage ru_majflt: 0                                                        
Child rusage ru_inblock: 6552                                                    
Child rusage ru_oublock: 51016                                                   
Child rusage ru_nvcsw: 18280                                                     
Child rusage ru_nivcsw: 29984                                                    
Status: PASSED                                                                   
Ended: 1502541117.52 

The CPU usage is given with data extracted from /proc/<pid>/stat and given in units of clock ticks:

• utime is the amount of time the process has been scheduled in user mode
• stime is the amount of time it has been scheduled in kernel mode
• cutime is the time the process's children were scheduled in user mode
• cstime is the time they were scheduled in kernel mode

And the following is also available from the resource usage information provided from getrusage(), representing the resource usage of the calling process, including all threads, as well as the children and their descendants:

• ru_utime is the user CPU time used in seconds
• ru_stime is the system CPU time used in seconds
• ru_maxrss is the maximum resident set size in KB
• ru_minflt is the number of page faults without I/O activity
• ru_majflt is the number of page faults with required I/O activity
• ru_inblock is the count of filesystem inputs
• ru_oublock is the count of filesystem outputs
• ru_nvcsw is the count of times a process yielded voluntarily
• ru_nivcsw is the count of times a process was forced to yield

Finally, the disk access statistics are provided from /proc/<pid>/io as follows:

• rchar is the number of bytes read from storage
• wchar is the number of bytes written to disk
• syscr is the estimated number of read I/O operations 
• syscw is the estimated number of write I/O operations 
• read_bytes is the number of bytes read from storage (estimate-accurate for block-backed filesystems)
• write_bytes is the estimated number of bytes written to the storage layer 
• cancelled_write_bytes is the number of bytes written that did not happen, by truncating page cache

There's more...

You can also obtain a graphical representation of the data using the pybootchartgui.py tool included in the Poky source. From your project's build folder, you can execute the following command to obtain a bootchart.png graphic in /tmp:

$ cd /optyocto/fsl-community-bsp/wandboard/$ /opt/yocto/fsl-community-bsp/sources/poky/scripts/pybootchartgui/pybootchartgui.py 
   tmp/buildstats/ -o /tmp

An example graphic is shown next:

Graphical build statistics documentation

See also

• Refer to the Linux kernel documentation for more details regarding the data obtained through the proc filesystem: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/Documentation/filesystems/proc.txt