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): |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame^] | 83 | bn = d.getVar('BUILDNAME') |
| 84 | bsdir = os.path.join(d.getVar('BUILDSTATS_BASE'), bn) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 85 | with open(os.path.join(logfile), "a") as f: |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 86 | elapsedtime = get_timedata("__timedata_task", d, e.time) |
| 87 | if elapsedtime: |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame^] | 88 | f.write(d.expand("${PF}: %s\n" % e.task)) |
| 89 | f.write(d.expand("Elapsed time: %0.2f seconds\n" % elapsedtime)) |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 90 | cpu, iostats, resources, childres = get_process_cputime(os.getpid()) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 91 | if cpu: |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 92 | f.write("utime: %s\n" % cpu['utime']) |
| 93 | f.write("stime: %s\n" % cpu['stime']) |
| 94 | f.write("cutime: %s\n" % cpu['cutime']) |
| 95 | f.write("cstime: %s\n" % cpu['cstime']) |
| 96 | for i in iostats: |
| 97 | f.write("IO %s: %s\n" % (i, iostats[i])) |
| 98 | rusages = ["ru_utime", "ru_stime", "ru_maxrss", "ru_minflt", "ru_majflt", "ru_inblock", "ru_oublock", "ru_nvcsw", "ru_nivcsw"] |
| 99 | for i in rusages: |
| 100 | f.write("rusage %s: %s\n" % (i, getattr(resources, i))) |
| 101 | for i in rusages: |
| 102 | f.write("Child rusage %s: %s\n" % (i, getattr(childres, i))) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 103 | if status is "passed": |
| 104 | f.write("Status: PASSED \n") |
| 105 | else: |
| 106 | f.write("Status: FAILED \n") |
| 107 | f.write("Ended: %0.2f \n" % e.time) |
| 108 | |
| 109 | python run_buildstats () { |
| 110 | import bb.build |
| 111 | import bb.event |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 112 | import time, subprocess, platform |
| 113 | |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame^] | 114 | bn = d.getVar('BUILDNAME') |
| 115 | bsdir = os.path.join(d.getVar('BUILDSTATS_BASE'), bn) |
| 116 | taskdir = os.path.join(bsdir, d.getVar('PF')) |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 117 | |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 118 | if isinstance(e, bb.event.BuildStarted): |
| 119 | ######################################################################## |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 120 | # If the kernel was not configured to provide I/O statistics, issue |
| 121 | # a one time warning. |
| 122 | ######################################################################## |
| 123 | if not os.path.isfile("/proc/%d/io" % os.getpid()): |
| 124 | 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)") |
| 125 | |
| 126 | ######################################################################## |
| 127 | # at first pass make the buildstats hierarchy and then |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 128 | # set the buildname |
| 129 | ######################################################################## |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 130 | bb.utils.mkdirhier(bsdir) |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 131 | set_buildtimedata("__timedata_build", d) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 132 | build_time = os.path.join(bsdir, "build_stats") |
| 133 | # write start of build into build_time |
| 134 | with open(build_time, "a") as f: |
| 135 | host_info = platform.uname() |
| 136 | f.write("Host Info: ") |
| 137 | for x in host_info: |
| 138 | if x: |
| 139 | f.write(x + " ") |
| 140 | f.write("\n") |
| 141 | f.write("Build Started: %0.2f \n" % time.time()) |
| 142 | |
| 143 | elif isinstance(e, bb.event.BuildCompleted): |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 144 | build_time = os.path.join(bsdir, "build_stats") |
| 145 | with open(build_time, "a") as f: |
| 146 | ######################################################################## |
| 147 | # Write build statistics for the build |
| 148 | ######################################################################## |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 149 | timedata = get_buildtimedata("__timedata_build", d) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 150 | if timedata: |
| 151 | time, cpu = timedata |
| 152 | # write end of build and cpu used into build_time |
| 153 | f.write("Elapsed time: %0.2f seconds \n" % (time)) |
| 154 | if cpu: |
| 155 | f.write("CPU usage: %0.1f%% \n" % cpu) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 156 | |
| 157 | if isinstance(e, bb.build.TaskStarted): |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 158 | set_timedata("__timedata_task", d, e.time) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 159 | bb.utils.mkdirhier(taskdir) |
| 160 | # write into the task event file the name and start time |
| 161 | with open(os.path.join(taskdir, e.task), "a") as f: |
| 162 | f.write("Event: %s \n" % bb.event.getName(e)) |
| 163 | f.write("Started: %0.2f \n" % e.time) |
| 164 | |
| 165 | elif isinstance(e, bb.build.TaskSucceeded): |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 166 | write_task_data("passed", os.path.join(taskdir, e.task), e, d) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 167 | if e.task == "do_rootfs": |
| 168 | bs = os.path.join(bsdir, "build_stats") |
| 169 | with open(bs, "a") as f: |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame^] | 170 | rootfs = d.getVar('IMAGE_ROOTFS') |
Patrick Williams | c0f7c04 | 2017-02-23 20:41:17 -0600 | [diff] [blame] | 171 | if os.path.isdir(rootfs): |
| 172 | try: |
| 173 | rootfs_size = subprocess.check_output(["du", "-sh", rootfs], |
| 174 | stderr=subprocess.STDOUT).decode('utf-8') |
| 175 | f.write("Uncompressed Rootfs size: %s" % rootfs_size) |
| 176 | except subprocess.CalledProcessError as err: |
| 177 | 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] | 178 | |
| 179 | elif isinstance(e, bb.build.TaskFailed): |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 180 | # Can have a failure before TaskStarted so need to mkdir here too |
| 181 | bb.utils.mkdirhier(taskdir) |
| 182 | write_task_data("failed", os.path.join(taskdir, e.task), e, d) |
Patrick Williams | c124f4f | 2015-09-15 14:41:29 -0500 | [diff] [blame] | 183 | ######################################################################## |
| 184 | # Lets make things easier and tell people where the build failed in |
| 185 | # build_status. We do this here because BuildCompleted triggers no |
| 186 | # matter what the status of the build actually is |
| 187 | ######################################################################## |
| 188 | build_status = os.path.join(bsdir, "build_stats") |
| 189 | with open(build_status, "a") as f: |
Patrick Williams | d8c66bc | 2016-06-20 12:57:21 -0500 | [diff] [blame] | 190 | 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] | 191 | } |
| 192 | |
| 193 | addhandler run_buildstats |
| 194 | run_buildstats[eventmask] = "bb.event.BuildStarted bb.event.BuildCompleted bb.build.TaskStarted bb.build.TaskSucceeded bb.build.TaskFailed" |
| 195 | |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame^] | 196 | python runqueue_stats () { |
| 197 | import buildstats |
| 198 | from bb import event, runqueue |
| 199 | # We should not record any samples before the first task has started, |
| 200 | # because that's the first activity shown in the process chart. |
| 201 | # Besides, at that point we are sure that the build variables |
| 202 | # are available that we need to find the output directory. |
| 203 | # The persistent SystemStats is stored in the datastore and |
| 204 | # closed when the build is done. |
| 205 | system_stats = d.getVar('_buildstats_system_stats', False) |
| 206 | if not system_stats and isinstance(e, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted)): |
| 207 | system_stats = buildstats.SystemStats(d) |
| 208 | d.setVar('_buildstats_system_stats', system_stats) |
| 209 | if system_stats: |
| 210 | # Ensure that we sample at important events. |
| 211 | done = isinstance(e, bb.event.BuildCompleted) |
| 212 | system_stats.sample(e, force=done) |
| 213 | if done: |
| 214 | system_stats.close() |
| 215 | d.delVar('_buildstats_system_stats') |
| 216 | } |
| 217 | |
| 218 | addhandler runqueue_stats |
| 219 | runqueue_stats[eventmask] = "bb.runqueue.sceneQueueTaskStarted bb.runqueue.runQueueTaskStarted bb.event.HeartbeatEvent bb.event.BuildCompleted bb.event.MonitorDiskEvent" |