| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 1 | BUILDSTATS_BASE = "${TMPDIR}/buildstats/" | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 2 |  | 
|  | 3 | ################################################################################ | 
|  | 4 | # Build statistics gathering. | 
|  | 5 | # | 
|  | 6 | # The CPU and Time gathering/tracking functions and bbevent inspiration | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 7 | # were written by Christopher Larson. | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 8 | # | 
|  | 9 | ################################################################################ | 
|  | 10 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 11 | def get_buildprocess_cputime(pid): | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 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 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 17 | def 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 | 
| Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 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 | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 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 |  | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 45 | def 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 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 50 | def set_timedata(var, d, server_time): | 
|  | 51 | d.setVar(var, server_time) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 52 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 53 | def get_timedata(var, d, end_time): | 
|  | 54 | oldtime = d.getVar(var, False) | 
|  | 55 | if oldtime is None: | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 56 | return | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 57 | return end_time - oldtime | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 58 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 59 | def set_buildtimedata(var, d): | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 60 | import time | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 61 | time = time.time() | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 62 | cputime = get_cputime() | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 63 | proctime = get_buildprocess_cputime(os.getpid()) | 
|  | 64 | d.setVar(var, (time, cputime, proctime)) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 65 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 66 | def get_buildtimedata(var, d): | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 67 | import time | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 68 | timedata = d.getVar(var, False) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 69 | if timedata is None: | 
|  | 70 | return | 
|  | 71 | oldtime, oldcpu, oldproc = timedata | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 72 | procdiff = get_buildprocess_cputime(os.getpid()) - oldproc | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 73 | cpudiff = get_cputime() - oldcpu | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 74 | end_time = time.time() | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 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 |  | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 82 | def write_task_data(status, logfile, e, d): | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 83 | with open(os.path.join(logfile), "a") as f: | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 84 | elapsedtime = get_timedata("__timedata_task", d, e.time) | 
|  | 85 | if elapsedtime: | 
| Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 86 | f.write(d.expand("${PF}: %s\n" % e.task)) | 
|  | 87 | f.write(d.expand("Elapsed time: %0.2f seconds\n" % elapsedtime)) | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 88 | cpu, iostats, resources, childres = get_process_cputime(os.getpid()) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 89 | if cpu: | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 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))) | 
| Andrew Geissler | 82c905d | 2020-04-13 13:39:40 -0500 | [diff] [blame] | 101 | if status == "passed": | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 102 | f.write("Status: PASSED \n") | 
|  | 103 | else: | 
|  | 104 | f.write("Status: FAILED \n") | 
|  | 105 | f.write("Ended: %0.2f \n" % e.time) | 
|  | 106 |  | 
|  | 107 | python run_buildstats () { | 
|  | 108 | import bb.build | 
|  | 109 | import bb.event | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 110 | import time, subprocess, platform | 
|  | 111 |  | 
| Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 112 | bn = d.getVar('BUILDNAME') | 
|  | 113 | bsdir = os.path.join(d.getVar('BUILDSTATS_BASE'), bn) | 
|  | 114 | taskdir = os.path.join(bsdir, d.getVar('PF')) | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 115 |  | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 116 | if isinstance(e, bb.event.BuildStarted): | 
|  | 117 | ######################################################################## | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 118 | # If the kernel was not configured to provide I/O statistics, issue | 
|  | 119 | # a one time warning. | 
|  | 120 | ######################################################################## | 
|  | 121 | if not os.path.isfile("/proc/%d/io" % os.getpid()): | 
|  | 122 | 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)") | 
|  | 123 |  | 
|  | 124 | ######################################################################## | 
|  | 125 | # at first pass make the buildstats hierarchy and then | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 126 | # set the buildname | 
|  | 127 | ######################################################################## | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 128 | bb.utils.mkdirhier(bsdir) | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 129 | set_buildtimedata("__timedata_build", d) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 130 | build_time = os.path.join(bsdir, "build_stats") | 
|  | 131 | # write start of build into build_time | 
|  | 132 | with open(build_time, "a") as f: | 
|  | 133 | host_info = platform.uname() | 
|  | 134 | f.write("Host Info: ") | 
|  | 135 | for x in host_info: | 
|  | 136 | if x: | 
|  | 137 | f.write(x + " ") | 
|  | 138 | f.write("\n") | 
| Andrew Geissler | 4ed12e1 | 2020-06-05 18:00:41 -0500 | [diff] [blame] | 139 | f.write("Build Started: %0.2f \n" % d.getVar('__timedata_build', False)[0]) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 140 |  | 
|  | 141 | elif isinstance(e, bb.event.BuildCompleted): | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 142 | build_time = os.path.join(bsdir, "build_stats") | 
|  | 143 | with open(build_time, "a") as f: | 
|  | 144 | ######################################################################## | 
|  | 145 | # Write build statistics for the build | 
|  | 146 | ######################################################################## | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 147 | timedata = get_buildtimedata("__timedata_build", d) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 148 | if timedata: | 
|  | 149 | time, cpu = timedata | 
|  | 150 | # write end of build and cpu used into build_time | 
|  | 151 | f.write("Elapsed time: %0.2f seconds \n" % (time)) | 
|  | 152 | if cpu: | 
|  | 153 | f.write("CPU usage: %0.1f%% \n" % cpu) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 154 |  | 
|  | 155 | if isinstance(e, bb.build.TaskStarted): | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 156 | set_timedata("__timedata_task", d, e.time) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 157 | bb.utils.mkdirhier(taskdir) | 
|  | 158 | # write into the task event file the name and start time | 
|  | 159 | with open(os.path.join(taskdir, e.task), "a") as f: | 
|  | 160 | f.write("Event: %s \n" % bb.event.getName(e)) | 
|  | 161 | f.write("Started: %0.2f \n" % e.time) | 
|  | 162 |  | 
|  | 163 | elif isinstance(e, bb.build.TaskSucceeded): | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 164 | write_task_data("passed", os.path.join(taskdir, e.task), e, d) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 165 | if e.task == "do_rootfs": | 
|  | 166 | bs = os.path.join(bsdir, "build_stats") | 
|  | 167 | with open(bs, "a") as f: | 
| Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 168 | rootfs = d.getVar('IMAGE_ROOTFS') | 
| Patrick Williams | c0f7c04 | 2017-02-23 20:41:17 -0600 | [diff] [blame] | 169 | if os.path.isdir(rootfs): | 
|  | 170 | try: | 
|  | 171 | rootfs_size = subprocess.check_output(["du", "-sh", rootfs], | 
|  | 172 | stderr=subprocess.STDOUT).decode('utf-8') | 
|  | 173 | f.write("Uncompressed Rootfs size: %s" % rootfs_size) | 
|  | 174 | except subprocess.CalledProcessError as err: | 
|  | 175 | bb.warn("Failed to get rootfs size: %s" % err.output.decode('utf-8')) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 176 |  | 
|  | 177 | elif isinstance(e, bb.build.TaskFailed): | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 178 | # Can have a failure before TaskStarted so need to mkdir here too | 
|  | 179 | bb.utils.mkdirhier(taskdir) | 
|  | 180 | write_task_data("failed", os.path.join(taskdir, e.task), e, d) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 181 | ######################################################################## | 
|  | 182 | # Lets make things easier and tell people where the build failed in | 
|  | 183 | # build_status. We do this here because BuildCompleted triggers no | 
|  | 184 | # matter what the status of the build actually is | 
|  | 185 | ######################################################################## | 
|  | 186 | build_status = os.path.join(bsdir, "build_stats") | 
|  | 187 | with open(build_status, "a") as f: | 
| Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 188 | f.write(d.expand("Failed at: ${PF} at task: %s \n" % e.task)) | 
| Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 189 | } | 
|  | 190 |  | 
|  | 191 | addhandler run_buildstats | 
|  | 192 | run_buildstats[eventmask] = "bb.event.BuildStarted bb.event.BuildCompleted bb.build.TaskStarted bb.build.TaskSucceeded bb.build.TaskFailed" | 
|  | 193 |  | 
| Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 194 | python runqueue_stats () { | 
|  | 195 | import buildstats | 
|  | 196 | from bb import event, runqueue | 
|  | 197 | # We should not record any samples before the first task has started, | 
|  | 198 | # because that's the first activity shown in the process chart. | 
|  | 199 | # Besides, at that point we are sure that the build variables | 
|  | 200 | # are available that we need to find the output directory. | 
|  | 201 | # The persistent SystemStats is stored in the datastore and | 
|  | 202 | # closed when the build is done. | 
|  | 203 | system_stats = d.getVar('_buildstats_system_stats', False) | 
|  | 204 | if not system_stats and isinstance(e, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted)): | 
|  | 205 | system_stats = buildstats.SystemStats(d) | 
|  | 206 | d.setVar('_buildstats_system_stats', system_stats) | 
|  | 207 | if system_stats: | 
|  | 208 | # Ensure that we sample at important events. | 
|  | 209 | done = isinstance(e, bb.event.BuildCompleted) | 
|  | 210 | system_stats.sample(e, force=done) | 
|  | 211 | if done: | 
|  | 212 | system_stats.close() | 
|  | 213 | d.delVar('_buildstats_system_stats') | 
|  | 214 | } | 
|  | 215 |  | 
|  | 216 | addhandler runqueue_stats | 
|  | 217 | runqueue_stats[eventmask] = "bb.runqueue.sceneQueueTaskStarted bb.runqueue.runQueueTaskStarted bb.event.HeartbeatEvent bb.event.BuildCompleted bb.event.MonitorDiskEvent" |