Coverage analysis update
Joel Sherrill
joel at rtems.org
Thu Jul 6 18:14:33 UTC 2017
On Thu, Jul 6, 2017 at 11:11 AM, Cillian O'Donnell <cpodonnell8 at gmail.com>
wrote:
> On 6 July 2017 at 15:34, Joel Sherrill <joel at rtems.org> wrote:
> >
> >
> > On Thu, Jul 6, 2017 at 5:53 AM, Cillian O'Donnell <cpodonnell8 at gmail.com
> >
> > wrote:
> >>
> >> On 6 July 2017 at 08:05, Chris Johns <chrisj at rtems.org> wrote:
> >> > On 05/07/2017 22:46, Cillian O'Donnell wrote:
> >> >>
> >> >> Now the thing is, I might have to run RTEMS Tester about 3 times for
> >> >> the full testsuite before I can get the report, as the covoar runs
> >> >> will often hang on an arbitrary method and have to be manually exited
> >> >> and re-run.
> >> >
> >> > How is covoar being run? Is it being run by the 'rtems-test' command?
> >>
> >> Yes covoar runs after the testsuite if a --coverage flag is included
> >> with rtems-test command.
> >> >
> >> >> The point that this happens is not repeatable and there's
> >> >> no error message to go on.
> >> >
> >> > Is it the covoar process that is stopping? Is it the process idle or
> >> > using 100%?
> >>
> >> Covoar locks up and becomes idle. Joel mentioned in the IRC meeting
> >> he's seen it before and I'll need to track down the exe causing it and
> >> debug it to get rid of this
> >
> >
> > There must be a misunderstanding. I have never seen covoar lock up
> > like this.
>
> Oh sorry, you must of just meant debugging covoar in general, picked
> it up wrong.
> >
> > It will ignore records when it thinks things are inconsistent. This can
> > occur
> > when a method appears in two different executables and has different
> > sizes. The cause of this is usually padding at the end of the method so
> > the subsequent method in memory starts on a nice cache-line alignment.
> > The code tries to recognize the nops/padding at the end and ignore them.
> > When the padding inserted by ld changes or the objdump output being
> > parsed changes, covoar needs to be adjusted.
> >
> > The ignored record message I saw is in the code that reads Couverture
> > trace records. The info in the record appears to be inconsistent with the
> > code to which it has been matched. This could be because the trace
> > record format has been changed or a simple bug.
> >
> > From what I have seen, it is likely that it is primarily bugs in input
> > processing.
> >
> > But the code to do the "big union" of the trace data has to iterate over
> > all tests and all coverage blocks. It can take a while to run. I guess
> > there could be an infinite loop in it. I always debugged it by having
> > a test case I could run in gdb.
> >
> >>
> >> >
> >> >> The only common theme is the methods will
> >> >> often be called thread...something. Even more rarely it will stop
> with
> >> >> the message 'resource temporarily unavailable'. I'm wondering is this
> >> >> normal behaviour for covoar on a long test-run? This never happens
> >> >> when running just the samples.
> >> >
> >> > It is not normal behavior.
> >
> >
> > +1
> >
> > Is Linux or covoar printing the message? It holds all data in memory
> while
> > doing the analysis. Is it consuming a lot of RAM?
>
> I done two rtems-test coverage runs there while monitoring 'top'
> output. The first run is successful and coverage report is generated
> and the second run produced IO Error: Resource temporarily unavailable
> on the second. Both times theres about 3.5-4GB RAM free and CPU runs
> at 70-80% so nothing seems to be strained there.
> Timecounter_Tick_simple is being checked before it happens. The output
> is
>
> 4000c9d8: 0a 80 00 03 bcs 4000c9e4 <_Timecounter_Tick_simple+0x78>
> 4000c9dc: 84 01 20 01 add %g4, 1, %g2
>
> bt = th->th_offset;
> 4000c9e0: 84 10 00 04 mov %g4, %g2
> _bt->sec += _bt2->sec;
> 4000c9e4: fa 06 e0 a0 ld [ %i3 + 0xa0 ], %i5
> 4000c9e8: 84 00 80 1d add %g2, %i5, %g2
> _tv->tv_usec = ((uint64_t)1000000 * (uint32_t)(_bt->frac >> 32)) >> 32;
> 4000c9ec: 39 00 03 d0 sethi %hi(0xf4000), %i4
> _ts->tv_nsec = ((uint64_t)1000000000 *
> 4000c9f0: 3b 0e e6 b2 sethi %hi(0x3b9ac800), %i5
> _tv->tv_usec = ((uint64_t)1000000 * (uint32_t)(_bt->frac >> 32)) >> 32;
> 4000c9f4: b8 17 22 40 or %i4, 0x240, %i4
> _ts->tv_nsec = ((uint64_t)1000000000 *
> 4000c9f8: ba 17 62 00 or %i5, 0x200, %i5
> _tv->tv_usec = ((uint64_t)1000000 * (uint32_t)(_bt->frac >> 32))
> >> 32;Exception in thread _stderr[c]:
> Traceback (most recent call last):
> File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
> self.run()
> File "/usr/lib/python2.7/threading.py", line 754, in run
> self.__target(*self.__args, **self.__kwargs)
> File "/home/cpod/development/rtems/test/rtems-tools/rtemstoolkit/
> execute.py",
> line 206, in _readthread
> _output_line(line, exe, prefix, out, count)
> File "/home/cpod/development/rtems/test/rtems-tools/rtemstoolkit/
> execute.py",
> line 184, in _output_line
> out(prefix + line)
> File "/home/cpod/development/rtems/test/rtems-tools/tester/rt/
> coverage.py",
> line 387, in output_handler
> log.notice(text, stdout_only = False)
> File "/home/cpod/development/rtems/test/rtems-tools/rtemstoolkit/
> log.py",
> line 104, in notice
> print(l)
> IOError: [Errno 11] Resource temporarily unavailable
>
This looks like qemu is running too long with an RTEMS executable. This
stack trace is RTEMS code. Not covoar code. Please check what executable
is consuming so much run-time before it is killed. This will change the
solution. :)
covoar spends a lot of time iterating over sets of containers and
executables.
There could be an infinite loop in it but it is using STL containers for
everything and is single threaded so I rather doubt it would go into an
infinite loop.
>
> >
> >>
> >> >> When a test run is successful it will also finish with a lot of these
> >> >> messages:
> >> >>
> >> >> *** Trace block is inconsistent with coverage map
> >> >> *** Trace block (0x4000c4fc - 0x4000c51f) for 36 bytes
> >> >> *** Coverage map
> >> >> /home/cpod/coverage_test/test/coverage/unlimited.exe.cov
> >> >> INFO: DesiredSymbols::mergeCoverageMap - Unable to merge coverage
> map
> >> >> for _Thread_queue_Extract_with_proxy because the sizes are different
> >> >
> >> > I wonder what sizes are different?
> >>
> >> For this one, Joel mentioned it could be something to do with nops
> >> being added or space not matching and to take a look at _Thread_
> >> queue_Extract_with_proxy in the objdump and see if I can dig up
> >> anything from that. That message appears for _Thread_
> >> queue_Extract_with_proxy on all tests from base_sp.exe to
> >> unlimited.exe when running the full testsuite and on a few instances
> >> it also mentions unable to merge coverage map for TOD_TICKS_PER_SECOND
> >> for the same reason. The mismatch is always 36 bytes.
> >
> >
> > You need to find the two executables it differs on and see why the size
> > is different. It processes them from first to last on the command line so
> > find the first one that has the symbol and compare the dump to that
> > one it is flagging as different.
>
> Will the 2 executables be say for example unlimited.exe from the build
> tree and the temporarily copied covoar executable unlimited.exe.cov?
> So libscore.a info matches the original unlimited.exe and something
> has changed in the covoar copies?
>
No. It will be unlimited and one of the tests before it on the covoar
command line. In particular, it should be the first one with the symbol
in question. Compare the objdump's.
> >>
> >>
> >> Also I wanted to mention, there is quite a bit of work from the 2
> >> previous students on the integration of the coverage work into RTEMS
> >> Tester, would you be interested in starting the merging process of
> >> this. It might take a while to get everything reviewed and make any
> >> necessary changes. At this point it is working. its just fixing bugs,
> >> which I'm working on at the moment.
> >
> >
> > Chris.. I suggested this. It seems the basic flow and integration of
> > coverage into the tester is good enough to review and merge.
> >
> > --joel
> >
> >>
> >>
> >> Thanks,
> >>
> >> Cillian.
> >> >
> >> > Chris
> >> _______________________________________________
> >> devel mailing list
> >> devel at rtems.org
> >> http://lists.rtems.org/mailman/listinfo/devel
> >
> >
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rtems.org/pipermail/devel/attachments/20170706/c73edc02/attachment-0002.html>
More information about the devel
mailing list