poky/meta/classes/buildstats.bbclass - mdmillerii/openbmc - Gitiles

 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):
     import subprocess, os, datetime
     cmds = d.getVar('BB_LOG_HOST_STAT_CMDS')
     if cmds is None:
         d.setVar("BB_LOG_HOST_STAT_ON_INTERVAL", "0")
         d.setVar("BB_LOG_HOST_STAT_ON_FAILURE", "0")
         bb.warn("buildstats: Collecting host data failed. Set BB_LOG_HOST_STAT_CMDS=\"command1 ; command2 ; ... \" in conf\/local.conf\n")
         return
     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()))
         for cmd in cmds.split(";"):
             if len(cmd) == 0:
                 continue
             try:
                 output = subprocess.check_output(cmd.split(), stderr=subprocess.STDOUT, timeout=1).decode('utf-8')
             except (subprocess.CalledProcessError, subprocess.TimeoutExpired, FileNotFoundError) as err:
                 output = "Error running command: %s\n%s\n" % (cmd, err)
             f.write("%s\n%s\n" % (cmd, output))
     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"), e, d)

     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(build_status, e, d)
 }

 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)
         system_stats.sample(e, force=done)
         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"
	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):
	import subprocess, os, datetime
	cmds = d.getVar('BB_LOG_HOST_STAT_CMDS')
	if cmds is None:
	d.setVar("BB_LOG_HOST_STAT_ON_INTERVAL", "0")
	d.setVar("BB_LOG_HOST_STAT_ON_FAILURE", "0")
	bb.warn("buildstats: Collecting host data failed. Set BB_LOG_HOST_STAT_CMDS=\"command1 ; command2 ; ... \" in conf\/local.conf\n")
	return
	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()))
	for cmd in cmds.split(";"):
	if len(cmd) == 0:
	continue
	try:
	output = subprocess.check_output(cmd.split(), stderr=subprocess.STDOUT, timeout=1).decode('utf-8')
	except (subprocess.CalledProcessError, subprocess.TimeoutExpired, FileNotFoundError) as err:
	output = "Error running command: %s\n%s\n" % (cmd, err)
	f.write("%s\n%s\n" % (cmd, output))
	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"), e, d)

	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(build_status, e, d)
	}

	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)
	system_stats.sample(e, force=done)
	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"