[Piglit] [PATCH 3/3] Optionally capture dmesg changes for each test and report them in a summary

Fri Sep 20 13:36:40 PDT 2013

I'll send a new patch, stay tuned.

Marek

On Fri, Sep 20, 2013 at 10:32 PM, Dylan Baker <baker.dylan.c at gmail.com> wrote:
> On Wednesday 18 September 2013 01:21:59 Marek Olšák wrote:
>> On Wed, Sep 18, 2013 at 1:04 AM, Dylan Baker <baker.dylan.c at gmail.com>
> wrote:
>> > On Wednesday 18 September 2013 00:48:45 Marek Olšák wrote:
>> >> On Tue, Sep 17, 2013 at 6:43 PM, Dylan Baker <baker.dylan.c at gmail.com>
>> >
>> > wrote:
>> >> > On Monday 16 September 2013 20:08:35 Marek Olšák wrote:
>> >> >> The Radeon driver writes GPU page faults to dmesg and we need to know
>> >> >> which
>> >> >> test caused them.
>> >> >>
>> >> >> If there is any change in dmesg during a test run, the test result is
>> >> >> changed as follows:
>> >> >> * pass -> dmesg-warn
>> >> >> * warn -> dmesg-warn
>> >> >> * fail -> dmesg-fail
>> >> >> Dmesg is captured before and after the test and the difference between
>> >> >> the
>> >> >> two is stored in the test summary.
>> >> >>
>> >> >> The piglit-run.py parameter which enables this behavior is --dmesg.
>> >> >> It's
>> >> >> also recommended to use -c0.
>> >> >> ---
>> >> >>
>> >> >>  framework/core.py          |  5 ++--
>> >> >>  framework/exectest.py      | 64
>> >> >>
>> >> >> +++++++++++++++++++++++++++++++++++++++++-----
>> >> >
>> >> > framework/shader_test.py   |
>> >> >
>> >> >>  4 +--
>> >> >>  framework/summary.py       | 26 ++++++++++++++-----
>> >> >>  piglit-run.py              |  6 ++++-
>> >> >>  templates/index.css        |  6 ++++-
>> >> >>  templates/test_result.mako |  7 ++++-
>> >> >>  7 files changed, 98 insertions(+), 20 deletions(-)
>> >> >>
>> >> >> diff --git a/framework/core.py b/framework/core.py
>> >> >> index 150a70c..9efae63 100644
>> >> >> --- a/framework/core.py
>> >> >> +++ b/framework/core.py
>> >> >>
>> >> >> @@ -364,13 +364,14 @@ class TestrunResult:
>> >> >>  class Environment:
>> >> >>      def __init__(self, concurrent=True, execute=True,
>> >> >>      include_filter=[],
>> >> >>
>> >> >> -                 exclude_filter=[], valgrind=False):
>> >> >>
>> >> >> +                 exclude_filter=[], valgrind=False, dmesg=False):
>> >> >>          self.concurrent = concurrent
>> >> >>          self.execute = execute
>> >> >>          self.filter = []
>> >> >>          self.exclude_filter = []
>> >> >>          self.exclude_tests = set()
>> >> >>          self.valgrind = valgrind
>> >> >>
>> >> >> +        self.dmesg = dmesg
>> >> >>
>> >> >>          """
>> >> >>          The filter lists that are read in should be a list of string
>> >> >>
>> >> >> objects, @@ -448,7 +449,7 @@ class Test:
>> >> >>              try:
>> >> >>                  status("running")
>> >> >>                  time_start = time.time()
>> >> >>
>> >> >> -                result = self.run(env.valgrind)
>> >> >> +                result = self.run(env.valgrind, env.dmesg)''
>> >> >
>> >> > Instead of passing env.valgrind and env.dmesg, let's just pass env as a
>> >> > single argument here and sort it out in the Test.run method.
>> >>
>> >> Will do.
>> >>
>> >> >>                  time_end = time.time()
>> >> >>
>> >> >>                  if 'time' not in result:
>> >> >>                      result['time'] = time_end - time_start
>> >> >>
>> >> >> diff --git a/framework/exectest.py b/framework/exectest.py
>> >> >> index 6ee550c..2e9f0a5 100644
>> >> >> --- a/framework/exectest.py
>> >> >> +++ b/framework/exectest.py
>> >> >>
>> >> >> @@ -35,8 +35,48 @@ if 'PIGLIT_PLATFORM' in os.environ:
>> >> >>  else:
>> >> >>      PIGLIT_PLATFORM = ''
>> >> >>
>> >> >> -
>> >> >> -# ExecTest: A shared base class for tests that simply run an
>> >> >> executable.
>> >> >> +def read_dmesg():
>> >> >> +    try:
>> >> >> +        proc = subprocess.Popen('dmesg',
>> >> >> +                                stdout=subprocess.PIPE,
>> >> >> +                                universal_newlines=True)
>> >> >> +        out, err = proc.communicate()
>> >> >> +    except OSError as e:
>> >> >> +        return None
>> >> >> +    return out
>> >> >> +
>> >> >> +def get_last_dmesg_timestamp(text):
>> >> >> +    for i in reversed(range(0, len(text)-1)):
>> >> >> +        if text[i] == '\n':
>> >> >> +            line = text[i+1:]
>> >> >> +            for right_bracket, char in enumerate(line):
>> >> >> +                if char == ']':
>> >> >> +                    return line[:right_bracket+1]
>> >> >> +            return None
>> >> >> +    return None
>> >> >> +
>> >> >> +def get_dmesg_diff(old, new):
>> >> >> +    ts = get_last_dmesg_timestamp(old)
>> >> >> +    if ts == None:
>> >> >> +        return ''
>> >> >> +
>> >> >> +    start = 0
>> >> >> +    end = len(new)-1
>> >> >> +
>> >> >> +    while True:
>> >> >> +        pos = new.find(ts, start, end)
>> >> >> +        if pos == -1:
>> >> >> +            break
>> >> >> +        start = pos+len(ts)
>> >> >> +
>> >> >> +    pos = new.find('\n', start, end)
>> >> >> +    if (pos == -1):
>> >> >> +        return ''
>> >> >> +    start = pos+1
>> >> >> +    return new[start:end]
>> >> >
>> >> > I have a couple of problems with this section:
>> >> > 1) Please leave some comments, I'm having trouble following what you're
>> >> > trying to do here
>> >> > 2) This feels really hacky. I'd really like to see a more elegent
>> >> > solution
>> >> > to reading dmesg. What about a class that reads dmesg in the
>> >> > constructor,
>> >> > and has a method that either returns false or new entries to dmesg
>> >> > since
>> >> > it was called.
>> >>
>> >> It's dumb structured programming. I'm not a python guru, so that's
>> >> what I came up with. I'll try to add a class for it.
>> >
>> > While I think a class would be more elegant, I'd settle for some comments
>> > and polish. Looking at this I'm certain it can be optimized and polished
>> > as-is, but without a good understanding of what's going in and what's
>> > supposed to come out I can't help.
>>
>> Ah yes.
>>
>> get_last_dmesg_timestamp returns the dmesg timestamp from the last
>> line of the string. For example, if dmesg|tail -n1 returns this:
>> "[43470.939859] VM fault (0x04, vmid 4) at page 2119, read from TC (8)"
>>
>> get_last_dmesg_timestamp returns this:
>> "[43470.939859]"
>>
>> That's used on the old dmesg log. Then, get_dmesg_diff finds the
>> position of the last occurence of the timestamp string in the new
>> dmesg log and moves the position behind the timestamp (start =
>> pos+len(ts)), then it finds the next '\n' to get the position of the
>> next line. The rest of the dmesg log is returned, because it's always
>> newer than the timestamp.
>>
>> Marek
>
> You know, I still like the class Idea, but I'll just work on that myself after
> thiese patches land. If you'll add these comments (or something similar) to
> the functions in question you have my reviewed-by.