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