1BUILDSTATS_BASE = "${TMPDIR}/buildstats/" 2 3################################################################################ 4# Build statistics gathering. 5# 6# The CPU and Time gathering/tracking functions and bbevent inspiration 7# were written by Christopher Larson. 8# 9################################################################################ 10 11def get_buildprocess_cputime(pid): 12 with open("/proc/%d/stat" % pid, "r") as f: 13 fields = f.readline().rstrip().split() 14 # 13: utime, 14: stime, 15: cutime, 16: cstime 15 return sum(int(field) for field in fields[13:16]) 16 17def get_process_cputime(pid): 18 import resource 19 with open("/proc/%d/stat" % pid, "r") as f: 20 fields = f.readline().rstrip().split() 21 stats = { 22 'utime' : fields[13], 23 'stime' : fields[14], 24 'cutime' : fields[15], 25 'cstime' : fields[16], 26 } 27 iostats = {} 28 if os.path.isfile("/proc/%d/io" % pid): 29 with open("/proc/%d/io" % pid, "r") as f: 30 while True: 31 i = f.readline().strip() 32 if not i: 33 break 34 if not ":" in i: 35 # one more extra line is appended (empty or containing "0") 36 # most probably due to race condition in kernel while 37 # updating IO stats 38 break 39 i = i.split(": ") 40 iostats[i[0]] = i[1] 41 resources = resource.getrusage(resource.RUSAGE_SELF) 42 childres = resource.getrusage(resource.RUSAGE_CHILDREN) 43 return stats, iostats, resources, childres 44 45def get_cputime(): 46 with open("/proc/stat", "r") as f: 47 fields = f.readline().rstrip().split()[1:] 48 return sum(int(field) for field in fields) 49 50def set_timedata(var, d, server_time): 51 d.setVar(var, server_time) 52 53def get_timedata(var, d, end_time): 54 oldtime = d.getVar(var, False) 55 if oldtime is None: 56 return 57 return end_time - oldtime 58 59def set_buildtimedata(var, d): 60 import time 61 time = time.time() 62 cputime = get_cputime() 63 proctime = get_buildprocess_cputime(os.getpid()) 64 d.setVar(var, (time, cputime, proctime)) 65 66def get_buildtimedata(var, d): 67 import time 68 timedata = d.getVar(var, False) 69 if timedata is None: 70 return 71 oldtime, oldcpu, oldproc = timedata 72 procdiff = get_buildprocess_cputime(os.getpid()) - oldproc 73 cpudiff = get_cputime() - oldcpu 74 end_time = time.time() 75 timediff = end_time - oldtime 76 if cpudiff > 0: 77 cpuperc = float(procdiff) * 100 / cpudiff 78 else: 79 cpuperc = None 80 return timediff, cpuperc 81 82def write_task_data(status, logfile, e, d): 83 with open(os.path.join(logfile), "a") as f: 84 elapsedtime = get_timedata("__timedata_task", d, e.time) 85 if elapsedtime: 86 f.write(d.expand("${PF}: %s\n" % e.task)) 87 f.write(d.expand("Elapsed time: %0.2f seconds\n" % elapsedtime)) 88 cpu, iostats, resources, childres = get_process_cputime(os.getpid()) 89 if cpu: 90 f.write("utime: %s\n" % cpu['utime']) 91 f.write("stime: %s\n" % cpu['stime']) 92 f.write("cutime: %s\n" % cpu['cutime']) 93 f.write("cstime: %s\n" % cpu['cstime']) 94 for i in iostats: 95 f.write("IO %s: %s\n" % (i, iostats[i])) 96 rusages = ["ru_utime", "ru_stime", "ru_maxrss", "ru_minflt", "ru_majflt", "ru_inblock", "ru_oublock", "ru_nvcsw", "ru_nivcsw"] 97 for i in rusages: 98 f.write("rusage %s: %s\n" % (i, getattr(resources, i))) 99 for i in rusages: 100 f.write("Child rusage %s: %s\n" % (i, getattr(childres, i))) 101 if status == "passed": 102 f.write("Status: PASSED \n") 103 else: 104 f.write("Status: FAILED \n") 105 f.write("Ended: %0.2f \n" % e.time) 106 107def write_host_data(logfile, e, d, type): 108 import subprocess, os, datetime 109 # minimum time allowed for each command to run, in seconds 110 time_threshold = 0.5 111 limit = 10 112 # the total number of commands 113 num_cmds = 0 114 msg = "" 115 if type == "interval": 116 # interval at which data will be logged 117 interval = d.getVar("BB_HEARTBEAT_EVENT", False) 118 if interval is None: 119 bb.warn("buildstats: Collecting host data at intervals failed. Set BB_HEARTBEAT_EVENT=\"<interval>\" in conf/local.conf for the interval at which host data will be logged.") 120 d.setVar("BB_LOG_HOST_STAT_ON_INTERVAL", "0") 121 return 122 interval = int(interval) 123 cmds = d.getVar('BB_LOG_HOST_STAT_CMDS_INTERVAL') 124 msg = "Host Stats: Collecting data at %d second intervals.\n" % interval 125 if cmds is None: 126 d.setVar("BB_LOG_HOST_STAT_ON_INTERVAL", "0") 127 bb.warn("buildstats: Collecting host data at intervals failed. Set BB_LOG_HOST_STAT_CMDS_INTERVAL=\"command1 ; command2 ; ... \" in conf/local.conf.") 128 return 129 if type == "failure": 130 cmds = d.getVar('BB_LOG_HOST_STAT_CMDS_FAILURE') 131 msg = "Host Stats: Collecting data on failure.\n" 132 msg += "Failed at task: " + e.task + "\n" 133 if cmds is None: 134 d.setVar("BB_LOG_HOST_STAT_ON_FAILURE", "0") 135 bb.warn("buildstats: Collecting host data on failure failed. Set BB_LOG_HOST_STAT_CMDS_FAILURE=\"command1 ; command2 ; ... \" in conf/local.conf.") 136 return 137 c_san = [] 138 for cmd in cmds.split(";"): 139 if len(cmd) == 0: 140 continue 141 num_cmds += 1 142 c_san.append(cmd) 143 if num_cmds == 0: 144 if type == "interval": 145 d.setVar("BB_LOG_HOST_STAT_ON_INTERVAL", "0") 146 if type == "failure": 147 d.setVar("BB_LOG_HOST_STAT_ON_FAILURE", "0") 148 return 149 150 # return if the interval is not enough to run all commands within the specified BB_HEARTBEAT_EVENT interval 151 if type == "interval": 152 limit = interval / num_cmds 153 if limit <= time_threshold: 154 d.setVar("BB_LOG_HOST_STAT_ON_INTERVAL", "0") 155 bb.warn("buildstats: Collecting host data failed. BB_HEARTBEAT_EVENT interval not enough to run the specified commands. Increase value of BB_HEARTBEAT_EVENT in conf/local.conf.") 156 return 157 158 # set the environment variables 159 path = d.getVar("PATH") 160 opath = d.getVar("BB_ORIGENV", False).getVar("PATH") 161 ospath = os.environ['PATH'] 162 os.environ['PATH'] = path + ":" + opath + ":" + ospath 163 with open(logfile, "a") as f: 164 f.write("Event Time: %f\nDate: %s\n" % (e.time, datetime.datetime.now())) 165 f.write("%s" % msg) 166 for c in c_san: 167 try: 168 output = subprocess.check_output(c.split(), stderr=subprocess.STDOUT, timeout=limit).decode('utf-8') 169 except (subprocess.CalledProcessError, subprocess.TimeoutExpired, FileNotFoundError) as err: 170 output = "Error running command: %s\n%s\n" % (c, err) 171 f.write("%s\n%s\n" % (c, output)) 172 # reset the environment 173 os.environ['PATH'] = ospath 174 175python run_buildstats () { 176 import bb.build 177 import bb.event 178 import time, subprocess, platform 179 180 bn = d.getVar('BUILDNAME') 181 ######################################################################## 182 # bitbake fires HeartbeatEvent even before a build has been 183 # triggered, causing BUILDNAME to be None 184 ######################################################################## 185 if bn is not None: 186 bsdir = os.path.join(d.getVar('BUILDSTATS_BASE'), bn) 187 taskdir = os.path.join(bsdir, d.getVar('PF')) 188 if isinstance(e, bb.event.HeartbeatEvent) and bb.utils.to_boolean(d.getVar("BB_LOG_HOST_STAT_ON_INTERVAL")): 189 bb.utils.mkdirhier(bsdir) 190 write_host_data(os.path.join(bsdir, "host_stats_interval"), e, d, "interval") 191 192 if isinstance(e, bb.event.BuildStarted): 193 ######################################################################## 194 # If the kernel was not configured to provide I/O statistics, issue 195 # a one time warning. 196 ######################################################################## 197 if not os.path.isfile("/proc/%d/io" % os.getpid()): 198 bb.warn("The Linux kernel on your build host was not configured to provide process I/O statistics. (CONFIG_TASK_IO_ACCOUNTING is not set)") 199 200 ######################################################################## 201 # at first pass make the buildstats hierarchy and then 202 # set the buildname 203 ######################################################################## 204 bb.utils.mkdirhier(bsdir) 205 set_buildtimedata("__timedata_build", d) 206 build_time = os.path.join(bsdir, "build_stats") 207 # write start of build into build_time 208 with open(build_time, "a") as f: 209 host_info = platform.uname() 210 f.write("Host Info: ") 211 for x in host_info: 212 if x: 213 f.write(x + " ") 214 f.write("\n") 215 f.write("Build Started: %0.2f \n" % d.getVar('__timedata_build', False)[0]) 216 217 elif isinstance(e, bb.event.BuildCompleted): 218 build_time = os.path.join(bsdir, "build_stats") 219 with open(build_time, "a") as f: 220 ######################################################################## 221 # Write build statistics for the build 222 ######################################################################## 223 timedata = get_buildtimedata("__timedata_build", d) 224 if timedata: 225 time, cpu = timedata 226 # write end of build and cpu used into build_time 227 f.write("Elapsed time: %0.2f seconds \n" % (time)) 228 if cpu: 229 f.write("CPU usage: %0.1f%% \n" % cpu) 230 231 if isinstance(e, bb.build.TaskStarted): 232 set_timedata("__timedata_task", d, e.time) 233 bb.utils.mkdirhier(taskdir) 234 # write into the task event file the name and start time 235 with open(os.path.join(taskdir, e.task), "a") as f: 236 f.write("Event: %s \n" % bb.event.getName(e)) 237 f.write("Started: %0.2f \n" % e.time) 238 239 elif isinstance(e, bb.build.TaskSucceeded): 240 write_task_data("passed", os.path.join(taskdir, e.task), e, d) 241 if e.task == "do_rootfs": 242 bs = os.path.join(bsdir, "build_stats") 243 with open(bs, "a") as f: 244 rootfs = d.getVar('IMAGE_ROOTFS') 245 if os.path.isdir(rootfs): 246 try: 247 rootfs_size = subprocess.check_output(["du", "-sh", rootfs], 248 stderr=subprocess.STDOUT).decode('utf-8') 249 f.write("Uncompressed Rootfs size: %s" % rootfs_size) 250 except subprocess.CalledProcessError as err: 251 bb.warn("Failed to get rootfs size: %s" % err.output.decode('utf-8')) 252 253 elif isinstance(e, bb.build.TaskFailed): 254 # Can have a failure before TaskStarted so need to mkdir here too 255 bb.utils.mkdirhier(taskdir) 256 write_task_data("failed", os.path.join(taskdir, e.task), e, d) 257 ######################################################################## 258 # Lets make things easier and tell people where the build failed in 259 # build_status. We do this here because BuildCompleted triggers no 260 # matter what the status of the build actually is 261 ######################################################################## 262 build_status = os.path.join(bsdir, "build_stats") 263 with open(build_status, "a") as f: 264 f.write(d.expand("Failed at: ${PF} at task: %s \n" % e.task)) 265 if bb.utils.to_boolean(d.getVar("BB_LOG_HOST_STAT_ON_FAILURE")): 266 write_host_data(os.path.join(bsdir, "host_stats_%s_failure" % e.task), e, d, "failure") 267} 268 269addhandler run_buildstats 270run_buildstats[eventmask] = "bb.event.BuildStarted bb.event.BuildCompleted bb.event.HeartbeatEvent bb.build.TaskStarted bb.build.TaskSucceeded bb.build.TaskFailed" 271 272python runqueue_stats () { 273 import buildstats 274 from bb import event, runqueue 275 # We should not record any samples before the first task has started, 276 # because that's the first activity shown in the process chart. 277 # Besides, at that point we are sure that the build variables 278 # are available that we need to find the output directory. 279 # The persistent SystemStats is stored in the datastore and 280 # closed when the build is done. 281 system_stats = d.getVar('_buildstats_system_stats', False) 282 if not system_stats and isinstance(e, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted)): 283 system_stats = buildstats.SystemStats(d) 284 d.setVar('_buildstats_system_stats', system_stats) 285 if system_stats: 286 # Ensure that we sample at important events. 287 done = isinstance(e, bb.event.BuildCompleted) 288 system_stats.sample(e, force=done) 289 if done: 290 system_stats.close() 291 d.delVar('_buildstats_system_stats') 292} 293 294addhandler runqueue_stats 295runqueue_stats[eventmask] = "bb.runqueue.sceneQueueTaskStarted bb.runqueue.runQueueTaskStarted bb.event.HeartbeatEvent bb.event.BuildCompleted bb.event.MonitorDiskEvent" 296