From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: by yocto-www.yoctoproject.org (Postfix, from userid 118) id 78F69E0071E; Tue, 8 Mar 2016 03:34:41 -0800 (PST) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on yocto-www.yoctoproject.org X-Spam-Level: X-Spam-Status: No, score=-2.6 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,RCVD_IN_DNSWL_LOW autolearn=ham version=3.3.1 X-Spam-HAM-Report: * -0.7 RCVD_IN_DNSWL_LOW RBL: Sender listed at http://www.dnswl.org/, low * trust * [74.125.82.46 listed in list.dnswl.org] * -1.9 BAYES_00 BODY: Bayes spam probability is 0 to 1% * [score: 0.0000] * 0.1 DKIM_SIGNED Message has a DKIM or DK signature, not necessarily * valid * -0.1 DKIM_VALID Message has at least one valid DKIM or DK signature Received: from mail-wm0-f46.google.com (mail-wm0-f46.google.com [74.125.82.46]) by yocto-www.yoctoproject.org (Postfix) with ESMTP id 6B13BE00443 for ; Tue, 8 Mar 2016 03:34:38 -0800 (PST) Received: by mail-wm0-f46.google.com with SMTP id l68so127031958wml.0 for ; Tue, 08 Mar 2016 03:34:38 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=intel-com.20150623.gappssmtp.com; s=20150623; h=subject:to:references:from:message-id:date:user-agent:mime-version :in-reply-to:content-transfer-encoding; bh=1hXGQYw4tjfKurMisknPy3tofhQwPYrlyKc4bdPXGhY=; b=EjdjXrMYjOkTVES2SrRr7yJIAAZoNPoc5mXXCH8VNC1PGMdoCGzEly3tgAaO3Kl0pl anUFExqdMh0MAQHoUC2jlljlnAxJKFkkKRbmOrb6GmUOHFsYZFC7lS9mNbEga9dOmGbP 2vGhJBWDmdDr/lBiH19DEvUPHpMI3mjnyq8YpKyb01QjRCqfzi1BjkTv4n6kIIOfr5zo qwKyQNEg1DEtiOQW14qSpbh82u6PPZSXHvXx+cC+1ilVNaoq6Jq7UspoafBIevcrdeQU +pOIlPNLldS+HDNKSp0HH+9YpVDICmld1EcG4iayYl8jLfE6LoWaq0ywqRsNDojIAxKw wjzg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:subject:to:references:from:message-id:date :user-agent:mime-version:in-reply-to:content-transfer-encoding; bh=1hXGQYw4tjfKurMisknPy3tofhQwPYrlyKc4bdPXGhY=; b=jkNl/H+IB8/dU5d/zsQ7Zq2gH8EkRfEK6n3zhOmDe763OpQh7RKWcKci1qwQMrEaF8 b8uKgP5kVWRVXY0m92XnjkswY3adUWbOimAk6n+rhMQMRBTvIEYL7tpnH819ocoJRChq FqeKhSSQfh36WjVKgR1RcRPQDnNeOM8SxjmnLStCML/e/39Voy5t3nvg4tyaPe6WUJFw NaE1cgcoYawdrCiis5fh90NRaNW7IpnPKgPdtBSzpMZMj6hFdDgATsl7D7CRndIcgqlp lts8IqhAKjOxGoIe8enhaYJlataVvya0lkILOaEf/e2OathMd6Nke/5nxbsn25xSq4wK zJxw== X-Gm-Message-State: AD7BkJKKIjaO5c2TI/uUbePCcW4XARCvBdtsnzrqHlAkX+tYOQq5u7hf1+14kKMAX6e2+6M3 X-Received: by 10.194.61.240 with SMTP id t16mr28343789wjr.27.1457436878199; Tue, 08 Mar 2016 03:34:38 -0800 (PST) Received: from [192.168.0.44] (host86-147-84-80.range86-147.btcentralplus.com. [86.147.84.80]) by smtp.googlemail.com with ESMTPSA id jf6sm2542001wjb.2.2016.03.08.03.34.37 for (version=TLSv1/SSLv3 cipher=OTHER); Tue, 08 Mar 2016 03:34:37 -0800 (PST) To: toaster@yoctoproject.org References: <1457381578-16239-1-git-send-email-elliot.smith@intel.com> <1457381578-16239-3-git-send-email-elliot.smith@intel.com> From: Michael Wood Message-ID: <56DEB8CC.6060404@intel.com> Date: Tue, 8 Mar 2016 11:34:36 +0000 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Thunderbird/38.5.1 MIME-Version: 1.0 In-Reply-To: <1457381578-16239-3-git-send-email-elliot.smith@intel.com> Subject: Re: [PATCH 2/2] toaster: rework task buildstats storage and display X-BeenThere: toaster@yoctoproject.org X-Mailman-Version: 2.1.13 Precedence: list List-Id: Web based interface for BitBake List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 08 Mar 2016 11:34:41 -0000 Content-Type: text/plain; charset=windows-1252; format=flowed Content-Transfer-Encoding: 7bit Thanks. Sent to openembedded-core and bitbake-devel and pushed to toaster-next. Michael On 07/03/16 20:12, Elliot Smith wrote: > The data available from buildstats is now more fine grained than > previously, so take advantage of that to enrich the data we save > against tasks: > > * Store the CPU usage for user and system separately, and display > them separately. > * Disk IO is now measured in bytes, not ms. Also store the > read/write bytes separately. > * Store started and ended times, as well as elapsed_time. This > will enable future features such as showing which tasks were > running at a particular point in the build. > > There was also a problem with how we were looking up the Task > object, which meant that the buildstats were being added to > new tasks which weren't correctly associated with the build. Fix > how we look up the Task (only looking for tasks which match the > build, and the task and recipe names in the build stats data) so > the build stats are associated with the correct task. > > [YOCTO #8842] > > Signed-off-by: Elliot Smith > --- > bitbake/lib/bb/ui/buildinfohelper.py | 72 ++++++++++------------ > .../orm/migrations/0005_task_field_separation.py | 48 +++++++++++++++ > bitbake/lib/toaster/orm/models.py | 18 +++++- > .../toastergui/templates/basebuildpage.html | 4 +- > bitbake/lib/toaster/toastergui/templates/task.html | 23 ++++--- > .../lib/toaster/toastergui/templates/tasks.html | 20 +++--- > bitbake/lib/toaster/toastergui/urls.py | 2 +- > bitbake/lib/toaster/toastergui/views.py | 55 +++++++++++------ > 8 files changed, 163 insertions(+), 79 deletions(-) > create mode 100644 bitbake/lib/toaster/orm/migrations/0005_task_field_separation.py > > diff --git a/bitbake/lib/bb/ui/buildinfohelper.py b/bitbake/lib/bb/ui/buildinfohelper.py > index 81abede..7fedb76 100644 > --- a/bitbake/lib/bb/ui/buildinfohelper.py > +++ b/bitbake/lib/bb/ui/buildinfohelper.py > @@ -50,6 +50,7 @@ from bb.msg import BBLogFormatter as formatter > from django.db import models > from pprint import pformat > import logging > +from datetime import datetime, timedelta > > from django.db import transaction, connection > > @@ -120,6 +121,12 @@ class ORMWrapper(object): > > return vars(self)[dictname][key] > > + def _timestamp_to_datetime(self, secs): > + """ > + Convert timestamp in seconds to Python datetime > + """ > + return datetime(1970, 1, 1) + timedelta(seconds=secs) > + > # pylint: disable=no-self-use > # we disable detection of no self use in functions because the methods actually work on the object > # even if they don't touch self anywhere > @@ -223,6 +230,28 @@ class ORMWrapper(object): > target.license_manifest_path = license_manifest_path > target.save() > > + def update_task_object(self, build, task_name, recipe_name, task_stats): > + """ > + Find the task for build which matches the recipe and task name > + to be stored > + """ > + task_to_update = Task.objects.get( > + build = build, > + task_name = task_name, > + recipe__name = recipe_name > + ) > + > + task_to_update.started = self._timestamp_to_datetime(task_stats['started']) > + task_to_update.ended = self._timestamp_to_datetime(task_stats['ended']) > + task_to_update.elapsed_time = (task_stats['ended'] - task_stats['started']) > + task_to_update.cpu_time_user = task_stats['cpu_time_user'] > + task_to_update.cpu_time_system = task_stats['cpu_time_system'] > + task_to_update.disk_io_read = task_stats['disk_io_read'] > + task_to_update.disk_io_write = task_stats['disk_io_write'] > + task_to_update.disk_io = task_stats['disk_io_read'] + task_stats['disk_io_write'] > + > + task_to_update.save() > + > def get_update_task_object(self, task_information, must_exist = False): > assert 'build' in task_information > assert 'recipe' in task_information > @@ -259,14 +288,6 @@ class ORMWrapper(object): > task_object.sstate_result = Task.SSTATE_FAILED > object_changed = True > > - # mark down duration if we have a start time and a current time > - if 'start_time' in task_information.keys() and 'end_time' in task_information.keys(): > - duration = task_information['end_time'] - task_information['start_time'] > - task_object.elapsed_time = duration > - object_changed = True > - del task_information['start_time'] > - del task_information['end_time'] > - > if object_changed: > task_object.save() > return task_object > @@ -1091,31 +1112,11 @@ class BuildInfoHelper(object): > > > def store_tasks_stats(self, event): > - for (taskfile, taskname, taskstats, recipename) in BuildInfoHelper._get_data_from_event(event): > - localfilepath = taskfile.split(":")[-1] > - assert localfilepath.startswith("/") > + task_data = BuildInfoHelper._get_data_from_event(event) > > - recipe_information = self._get_recipe_information_from_taskfile(taskfile) > - try: > - if recipe_information['file_path'].startswith(recipe_information['layer_version'].local_path): > - recipe_information['file_path'] = recipe_information['file_path'][len(recipe_information['layer_version'].local_path):].lstrip("/") > - > - recipe_object = Recipe.objects.get(layer_version = recipe_information['layer_version'], > - file_path__endswith = recipe_information['file_path'], > - name = recipename) > - except Recipe.DoesNotExist: > - logger.error("Could not find recipe for recipe_information %s name %s" , pformat(recipe_information), recipename) > - raise > - > - task_information = {} > - task_information['build'] = self.internal_state['build'] > - task_information['recipe'] = recipe_object > - task_information['task_name'] = taskname > - task_information['cpu_usage'] = taskstats['cpu_usage'] > - task_information['disk_io'] = taskstats['disk_io'] > - if 'elapsed_time' in taskstats: > - task_information['elapsed_time'] = taskstats['elapsed_time'] > - self.orm_wrapper.get_update_task_object(task_information) > + for (task_file, task_name, task_stats, recipe_name) in task_data: > + build = self.internal_state['build'] > + self.orm_wrapper.update_task_object(build, task_name, recipe_name, task_stats) > > def update_and_store_task(self, event): > assert 'taskfile' in vars(event) > @@ -1137,13 +1138,6 @@ class BuildInfoHelper(object): > recipe = self.orm_wrapper.get_update_recipe_object(recipe_information, True) > task_information = self._get_task_information(event,recipe) > > - if 'time' in vars(event): > - if not 'start_time' in self.internal_state['taskdata'][identifier]: > - self.internal_state['taskdata'][identifier]['start_time'] = event.time > - else: > - task_information['end_time'] = event.time > - task_information['start_time'] = self.internal_state['taskdata'][identifier]['start_time'] > - > task_information['outcome'] = self.internal_state['taskdata'][identifier]['outcome'] > > if 'logfile' in vars(event): > diff --git a/bitbake/lib/toaster/orm/migrations/0005_task_field_separation.py b/bitbake/lib/toaster/orm/migrations/0005_task_field_separation.py > new file mode 100644 > index 0000000..fb1196b > --- /dev/null > +++ b/bitbake/lib/toaster/orm/migrations/0005_task_field_separation.py > @@ -0,0 +1,48 @@ > +# -*- coding: utf-8 -*- > +from __future__ import unicode_literals > + > +from django.db import migrations, models > + > + > +class Migration(migrations.Migration): > + > + dependencies = [ > + ('orm', '0004_provides'), > + ] > + > + operations = [ > + migrations.RemoveField( > + model_name='task', > + name='cpu_usage', > + ), > + migrations.AddField( > + model_name='task', > + name='cpu_time_system', > + field=models.DecimalField(null=True, max_digits=8, decimal_places=2), > + ), > + migrations.AddField( > + model_name='task', > + name='cpu_time_user', > + field=models.DecimalField(null=True, max_digits=8, decimal_places=2), > + ), > + migrations.AddField( > + model_name='task', > + name='disk_io_read', > + field=models.IntegerField(null=True), > + ), > + migrations.AddField( > + model_name='task', > + name='disk_io_write', > + field=models.IntegerField(null=True), > + ), > + migrations.AddField( > + model_name='task', > + name='ended', > + field=models.DateTimeField(null=True), > + ), > + migrations.AddField( > + model_name='task', > + name='started', > + field=models.DateTimeField(null=True), > + ), > + ] > diff --git a/bitbake/lib/toaster/orm/models.py b/bitbake/lib/toaster/orm/models.py > index 93b5df3..182d355 100644 > --- a/bitbake/lib/toaster/orm/models.py > +++ b/bitbake/lib/toaster/orm/models.py > @@ -720,9 +720,23 @@ class Task(models.Model): > work_directory = models.FilePathField(max_length=255, blank=True) > script_type = models.IntegerField(choices=TASK_CODING, default=CODING_NA) > line_number = models.IntegerField(default=0) > - disk_io = models.IntegerField(null=True) > - cpu_usage = models.DecimalField(max_digits=8, decimal_places=2, null=True) > + > + # start/end times > + started = models.DateTimeField(null=True) > + ended = models.DateTimeField(null=True) > + > + # in seconds; this is stored to enable sorting > elapsed_time = models.DecimalField(max_digits=8, decimal_places=2, null=True) > + > + # in bytes; note that disk_io is stored to enable sorting > + disk_io = models.IntegerField(null=True) > + disk_io_read = models.IntegerField(null=True) > + disk_io_write = models.IntegerField(null=True) > + > + # in seconds > + cpu_time_user = models.DecimalField(max_digits=8, decimal_places=2, null=True) > + cpu_time_system = models.DecimalField(max_digits=8, decimal_places=2, null=True) > + > sstate_result = models.IntegerField(choices=SSTATE_RESULT, default=SSTATE_NA) > message = models.CharField(max_length=240) > logfile = models.FilePathField(max_length=255, blank=True) > diff --git a/bitbake/lib/toaster/toastergui/templates/basebuildpage.html b/bitbake/lib/toaster/toastergui/templates/basebuildpage.html > index 0dc71f5..ff9433e 100644 > --- a/bitbake/lib/toaster/toastergui/templates/basebuildpage.html > +++ b/bitbake/lib/toaster/toastergui/templates/basebuildpage.html > @@ -67,8 +67,8 @@ > {% block nav-buildtime %} >
  • Time
    • > {% endblock %} > - {% block nav-cpuusage %} > -
  • CPU usage
    • > + {% block nav-cputime %} > +
  • CPU time
    • > {% endblock %} > {% block nav-diskio %} >
  • Disk I/O
    • > diff --git a/bitbake/lib/toaster/toastergui/templates/task.html b/bitbake/lib/toaster/toastergui/templates/task.html > index ef628d9..5768262 100644 > --- a/bitbake/lib/toaster/toastergui/templates/task.html > +++ b/bitbake/lib/toaster/toastergui/templates/task.html > @@ -238,7 +238,7 @@ > > > {# Performance section - shown only for executed tasks #} > -{%if task.elapsed_time or task.cpu_usage or task.disk_io %} > +{%if task.elapsed_time or task.cpu_time_user or task.cpu_time_system or task.disk_io %} >

    Performance

    > {% endif %} >
    > @@ -249,19 +249,26 @@ > >
    {{task.elapsed_time|format_none_and_zero|floatformat:2}}
    > {% endif %} > - {% if task.cpu_usage > 0 %} > + {% if task.cpu_time_user > 0 %} >
    > - > - CPU usage > + > + User CPU time (secs) >
    > -
    {{task.cpu_usage|format_none_and_zero|floatformat:2}}%
    > +
    {{task.cpu_time_user|format_none_and_zero|floatformat:2}}
    > + {% endif %} > + {% if task.cpu_time_system > 0 %} > +
    > + > + System CPU time (secs) > +
    > +
    {{task.cpu_time_system|format_none_and_zero|floatformat:2}}
    > {% endif %} > {% if task.disk_io > 0 %} >
    > - > - Disk I/O (ms) > + > + Disk I/O (bytes) >
    > -
    {{task.disk_io|format_none_and_zero}}
    > +
    {{task.disk_io|format_none_and_zero|intcomma}}
    > {% endif %} >
    > > diff --git a/bitbake/lib/toaster/toastergui/templates/tasks.html b/bitbake/lib/toaster/toastergui/templates/tasks.html > index 353410f..23eb957 100644 > --- a/bitbake/lib/toaster/toastergui/templates/tasks.html > +++ b/bitbake/lib/toaster/toastergui/templates/tasks.html > @@ -1,4 +1,5 @@ > {% extends "basebuildpage.html" %} > +{% load humanize %} > {% load projecttags %} > > {% block title %} {{mainheading}} - {{build.target_set.all|dictsort:"target"|join:", "}} {{build.machine}} - {{build.project.name}} - Toaster{% endblock %} > @@ -20,13 +21,15 @@ >
  • Time
    • > {% endif %} > {% endblock %} > -{% block nav-cpuusage %} > - {% if 'CPU usage' == mainheading %} > -
  • CPU usage
    • > + > +{% block nav-cputime %} > + {% if 'CPU time' == mainheading %} > +
  • CPU time
    • > {% else %} > -
  • CPU usage
    • > +
  • CPU time
    • > {% endif %} > {% endblock %} > + > {% block nav-diskio %} > {% if 'Disk I/O' == mainheading %} >
  • Disk I/O
    • > @@ -107,11 +110,14 @@ > > {{task.elapsed_time|format_none_and_zero|floatformat:2}} > > - > - {{task.cpu_usage|format_none_and_zero|floatformat:2}}{% if task.cpu_usage %}%{% endif %} > + > + {{task.cpu_time_system|format_none_and_zero|floatformat:2}} > + > + > + {{task.cpu_time_user|format_none_and_zero|floatformat:2}} > > > - {{task.disk_io|format_none_and_zero}} > + {{task.disk_io|format_none_and_zero|intcomma}} > > > > diff --git a/bitbake/lib/toaster/toastergui/urls.py b/bitbake/lib/toaster/toastergui/urls.py > index 4aa6488..400580a 100644 > --- a/bitbake/lib/toaster/toastergui/urls.py > +++ b/bitbake/lib/toaster/toastergui/urls.py > @@ -64,7 +64,7 @@ urlpatterns = patterns('toastergui.views', > url(r'^build/(?P\d+)/configuration$', 'configuration', name='configuration'), > url(r'^build/(?P\d+)/configvars$', 'configvars', name='configvars'), > url(r'^build/(?P\d+)/buildtime$', 'buildtime', name='buildtime'), > - url(r'^build/(?P\d+)/cpuusage$', 'cpuusage', name='cpuusage'), > + url(r'^build/(?P\d+)/cputime$', 'cputime', name='cputime'), > url(r'^build/(?P\d+)/diskio$', 'diskio', name='diskio'), > > # image information dir > diff --git a/bitbake/lib/toaster/toastergui/views.py b/bitbake/lib/toaster/toastergui/views.py > index bd11892..85ca9be 100755 > --- a/bitbake/lib/toaster/toastergui/views.py > +++ b/bitbake/lib/toaster/toastergui/views.py > @@ -1005,11 +1005,11 @@ def tasks_common(request, build_id, variant, task_anchor): > object_search_display="disk I/O data" > filter_search_display="tasks" > (pagesize, orderby) = _get_parameters_values(request, 25, 'disk_io:-') > - elif 'cpuusage' == variant: > - title_variant='CPU usage' > - object_search_display="CPU usage data" > + elif 'cputime' == variant: > + title_variant='CPU time' > + object_search_display="CPU time data" > filter_search_display="tasks" > - (pagesize, orderby) = _get_parameters_values(request, 25, 'cpu_usage:-') > + (pagesize, orderby) = _get_parameters_values(request, 25, 'cpu_time_system:-') > else : > title_variant='Tasks' > object_search_display="tasks" > @@ -1161,23 +1161,38 @@ def tasks_common(request, build_id, variant, task_anchor): > del tc_time['clclass'] > tc_cache['hidden']='1' > > - tc_cpu={ > - 'name':'CPU usage', > - 'qhelp':'The percentage of task CPU utilization', > - 'orderfield': _get_toggle_order(request, "cpu_usage", True), > - 'ordericon':_get_toggle_order_icon(request, "cpu_usage"), > - 'orderkey' : 'cpu_usage', > - 'clclass': 'cpu_used', 'hidden' : 1, > + tc_cpu_time_system={ > + 'name':'System CPU time (secs)', > + 'qhelp':'Total amount of time spent executing in kernel mode, in ' + > + 'seconds. Note that this time can be greater than the task ' + > + 'time due to parallel execution.', > + 'orderfield': _get_toggle_order(request, "cpu_time_system", True), > + 'ordericon':_get_toggle_order_icon(request, "cpu_time_system"), > + 'orderkey' : 'cpu_time_system', > + 'clclass': 'cpu_time_system', 'hidden' : 1, > } > > - if 'cpuusage' == variant: > - tc_cpu['hidden']='0' > - del tc_cpu['clclass'] > + tc_cpu_time_user={ > + 'name':'User CPU time (secs)', > + 'qhelp':'Total amount of time spent executing in user mode, in seconds. ' + > + 'Note that this time can be greater than the task time due to ' + > + 'parallel execution.', > + 'orderfield': _get_toggle_order(request, "cpu_time_user", True), > + 'ordericon':_get_toggle_order_icon(request, "cpu_time_user"), > + 'orderkey' : 'cpu_time_user', > + 'clclass': 'cpu_time_user', 'hidden' : 1, > + } > + > + if 'cputime' == variant: > + tc_cpu_time_system['hidden']='0' > + tc_cpu_time_user['hidden']='0' > + del tc_cpu_time_system['clclass'] > + del tc_cpu_time_user['clclass'] > tc_cache['hidden']='1' > > tc_diskio={ > - 'name':'Disk I/O (ms)', > - 'qhelp':'Number of miliseconds the task spent doing disk input and output', > + 'name':'Disk I/O (bytes)', > + 'qhelp':'Number of bytes written to and read from the disk during the task', > 'orderfield': _get_toggle_order(request, "disk_io", True), > 'ordericon':_get_toggle_order_icon(request, "disk_io"), > 'orderkey' : 'disk_io', > @@ -1208,7 +1223,8 @@ def tasks_common(request, build_id, variant, task_anchor): > tc_outcome, > tc_cache, > tc_time, > - tc_cpu, > + tc_cpu_time_system, > + tc_cpu_time_user, > tc_diskio, > ]} > > @@ -1229,9 +1245,8 @@ def buildtime(request, build_id): > def diskio(request, build_id): > return tasks_common(request, build_id, 'diskio', '') > > -def cpuusage(request, build_id): > - return tasks_common(request, build_id, 'cpuusage', '') > - > +def cputime(request, build_id): > + return tasks_common(request, build_id, 'cputime', '') > > def recipes(request, build_id): > template = 'recipes.html'