[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Vlad Zakharov]

Latest versions of make produce a bit different output than older
versions do. They also print number of line in Makefile where the
failure occurred.

E.g. latest make produces the following output:
---------------------------------->8------------------------------------
GNUmakefile:277: recipe for target 'cgiedit.o' failed
make[2]: *** [cgiedit.o] Error 1
package/pkg-generic.mk:201: recipe for target '/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built' failed
make[1]: *** [/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built] Error 2
Makefile:88: recipe for target '_all' failed
make: *** [_all] Error 2
make: Leaving directory '/home/buildroot/autobuild/run/instance-2/buildroot'
---------------------------------->8------------------------------------

When with old version we get something like:
---------------------------------->8------------------------------------
make[2]: *** [cgiedit.o] Error 1
make[1]: *** [/home/buildroot/autobuild/run/instance-1/output/build/privoxy-3.0.26/.stamp_built] Error 2
make: *** [_all] Error 2
make: Leaving directory `/home/buildroot/autobuild/run/instance-1/buildroot'
---------------------------------->8------------------------------------

So latest make produce much more "noise" and we have to analyze
at least 4 last lines of log to be sure that they contain a line
with failure reason.

Signed-off-by: Vlad Zakharov <vzakhar@synopsys.com>
---
 scripts/autobuild-run | 2 +-
 web/import.inc.php    | 2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/scripts/autobuild-run b/scripts/autobuild-run
index 0fa5fdc..8c86a29 100755
--- a/scripts/autobuild-run
+++ b/scripts/autobuild-run
@@ -667,7 +667,7 @@ def send_results(result, **kwargs):
     def get_failure_reason():
         # Output is a tuple (package, version), or None.
         lastlines = decode_bytes(subprocess.Popen(
-            ["tail", "-n", "3", os.path.join(outputdir, "logfile")],
+            ["tail", "-n", "4", os.path.join(outputdir, "logfile")],
             stdout=subprocess.PIPE).communicate()[0]).splitlines()
 
         regexp = re.compile(r'make: \*\*\* .*/(?:build|toolchain)/([^/]*)/')
diff --git a/web/import.inc.php b/web/import.inc.php
index 243a1f3..3be1251 100644
--- a/web/import.inc.php
+++ b/web/import.inc.php
@@ -102,7 +102,7 @@ function import_result($buildid, $filename)
       $reason = "none";
     else {
 	$tmp = Array();
-	exec("tail -3 " . $thisbuildfinaldir . "build-end.log | grep -v '\[_all\]' | grep 'make.*: \*\*\*' | sed 's,.*\[\([^\]*\)\] Error.*,\\1,' | sed 's,.*/build/\([^/]*\)/.*,\\1,'", $tmp);
+	exec("tail -4 " . $thisbuildfinaldir . "build-end.log | grep -v '\[_all\]' | grep 'make.*: \*\*\*' | sed 's,.*\[\([^\]*\)\] Error.*,\\1,' | sed 's,.*/build/\([^/]*\)/.*,\\1,'", $tmp);
 	if (trim($tmp[0]))
 	  $reason = $tmp[0];
 	else
-- 
2.5.5

[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Thomas Petazzoni]

Hello,

On Wed, 26 Oct 2016 13:45:17 +0300, Vlad Zakharov wrote:
> Latest versions of make produce a bit different output than older
> versions do. They also print number of line in Makefile where the
> failure occurred.
> 
> E.g. latest make produces the following output:
> ---------------------------------->8------------------------------------  
> GNUmakefile:277: recipe for target 'cgiedit.o' failed
> make[2]: *** [cgiedit.o] Error 1
> package/pkg-generic.mk:201: recipe for target '/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built' failed
> make[1]: *** [/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built] Error 2
> Makefile:88: recipe for target '_all' failed
> make: *** [_all] Error 2
> make: Leaving directory '/home/buildroot/autobuild/run/instance-2/buildroot'
> ---------------------------------->8------------------------------------  
> 
> When with old version we get something like:
> ---------------------------------->8------------------------------------  
> make[2]: *** [cgiedit.o] Error 1
> make[1]: *** [/home/buildroot/autobuild/run/instance-1/output/build/privoxy-3.0.26/.stamp_built] Error 2
> make: *** [_all] Error 2
> make: Leaving directory `/home/buildroot/autobuild/run/instance-1/buildroot'
> ---------------------------------->8------------------------------------  
> 
> So latest make produce much more "noise" and we have to analyze
> at least 4 last lines of log to be sure that they contain a line
> with failure reason.
> 
> Signed-off-by: Vlad Zakharov <vzakhar@synopsys.com>

I'm a little bit worried about this change, because we did a fairly
similar change in commit 585358277b80dfe18b17b13035675bfe7db48b20,
which I quickly reverted in commit
a616a8c592caf2a9c9ce82ac1cac9681775452d3 because it was breaking
everything. Following 585358277b80dfe18b17b13035675bfe7db48b20, for a
large number of builds, the detected build failure was "all" or
"all-recursive".

So we really want to be extra careful, by testing the logic change on
existing build results first.

Also, another thing that is annoying that we have two places where we
calculate the failure reason: in autobuild-run (on the autobuild slave)
and in import.inc.php (which runs on autobuild.b.o when an autobuild
result is submitted).

Historically, the failure reason was only extracted in import.inc.php,
from the submitted log. But later on, some logic was added in
autobuild-run to extract the reason, which was used to make sure we
keep in build-end.log not just the 500 last lines of the build, but
the entire build log from the beginning of the failing package (which
requires knowing the package that failed building, and therefore
calculating the reason).

It would be great to get rid of this duplication, and have
autobuild-run calculate the reason, store it in a "reason" file,
submitted to autobuild.b.o as part of the tarball, and import.inc.php
simply reads that file. This way we have the reason calculation logic
in just one place.

Thanks,

Thomas
-- 
Thomas Petazzoni, CTO, Free Electrons
Embedded Linux and Kernel engineering
http://free-electrons.com

[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Vlad Zakharov]

Hi Thomas.

On Wed, 2016-10-26 at 13:52 +0200, Thomas Petazzoni wrote:
> Hello,
> 
> On Wed, 26 Oct 2016 13:45:17 +0300, Vlad Zakharov wrote:
> > 
> > Latest versions of make produce a bit different output than older
> > versions do. They also print number of line in Makefile where the
> > failure occurred.
> > 
> > E.g. latest make produces the following output:
> > ---------------------------------->8------------------------------------??
> > GNUmakefile:277: recipe for target 'cgiedit.o' failed
> > make[2]: *** [cgiedit.o] Error 1
> > package/pkg-generic.mk:201: recipe for target '/home/buildroot/autobuild/run/instance-2/output/build/privoxy-
> > 3.0.26/.stamp_built' failed
> > make[1]: *** [/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built] Error 2
> > Makefile:88: recipe for target '_all' failed
> > make: *** [_all] Error 2
> > make: Leaving directory '/home/buildroot/autobuild/run/instance-2/buildroot'
> > ---------------------------------->8------------------------------------??
> > 
> > When with old version we get something like:
> > ---------------------------------->8------------------------------------??
> > make[2]: *** [cgiedit.o] Error 1
> > make[1]: *** [/home/buildroot/autobuild/run/instance-1/output/build/privoxy-3.0.26/.stamp_built] Error 2
> > make: *** [_all] Error 2
> > make: Leaving directory `/home/buildroot/autobuild/run/instance-1/buildroot'
> > ---------------------------------->8------------------------------------??
> > 
> > So latest make produce much more "noise" and we have to analyze
> > at least 4 last lines of log to be sure that they contain a line
> > with failure reason.
> > 
> > Signed-off-by: Vlad Zakharov <vzakhar@synopsys.com>
> 
> I'm a little bit worried about this change, because we did a fairly
> similar change in commit 585358277b80dfe18b17b13035675bfe7db48b20,
> which I quickly reverted in commit
> a616a8c592caf2a9c9ce82ac1cac9681775452d3 because it was breaking
> everything. Following 585358277b80dfe18b17b13035675bfe7db48b20, for a
> large number of builds, the detected build failure was "all" or
> "all-recursive".
> 
> So we really want to be extra careful, by testing the logic change on
> existing build results first.

But I haven't updated the regex, only lines count printed by tail.
The regex suggested by?585358277b80dfe18b17b13035675bfe7db48b20 was able to recognize both
"make:" and "make[n]:". Note that "all" and "all-recursive" targets appears with the second variant.
I guess that my changes would not affect failure reason parsing from output of older make versions.

I can offer another solution:
We analyze last 4 lines but use the last matched string. As I understand from my experience of analyzing build logs the
string with a real build failure as a rule comes after "all" and "all-recursive".

> 
> Also, another thing that is annoying that we have two places where we
> calculate the failure reason: in autobuild-run (on the autobuild slave)
> and in import.inc.php (which runs on autobuild.b.o when an autobuild
> result is submitted).
> 
> Historically, the failure reason was only extracted in import.inc.php,
> from the submitted log. But later on, some logic was added in
> autobuild-run to extract the reason, which was used to make sure we
> keep in build-end.log not just the 500 last lines of the build, but
> the entire build log from the beginning of the failing package (which
> requires knowing the package that failed building, and therefore
> calculating the reason).
> 
> It would be great to get rid of this duplication, and have
> autobuild-run calculate the reason, store it in a "reason" file,
> submitted to autobuild.b.o as part of the tarball, and import.inc.php
> simply reads that file. This way we have the reason calculation logic
> in just one place.

I can write a separate patch that will exclude duplication and store failure reason in a "reason" file.?

> 
> Thanks,
> 
> Thomas
-- 
Best regards,
Vlad Zakharov <vzakhar@synopsys.com>

[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Vlad Zakharov]

Hi Thomas, all.

I strongly believe that something should be done with the issue.
Of course the approach that I have suggested may not be the best but we can discuss the subject to find better solution.
It is not a good idea to leave everything as is because failure reason detection totally doesn't work if use up-to-date
"make" utility.?

Thank you.?

On Wed, 2016-10-26 at 12:29 +0000, Vlad Zakharov wrote:
> Hi Thomas.
> 
> On Wed, 2016-10-26 at 13:52 +0200, Thomas Petazzoni wrote:
> > 
> > Hello,
> > 
> > On Wed, 26 Oct 2016 13:45:17 +0300, Vlad Zakharov wrote:
> > > 
> > > 
> > > Latest versions of make produce a bit different output than older
> > > versions do. They also print number of line in Makefile where the
> > > failure occurred.
> > > 
> > > E.g. latest make produces the following output:
> > > ---------------------------------->8------------------------------------??
> > > GNUmakefile:277: recipe for target 'cgiedit.o' failed
> > > make[2]: *** [cgiedit.o] Error 1
> > > package/pkg-generic.mk:201: recipe for target '/home/buildroot/autobuild/run/instance-2/output/build/privoxy-
> > > 3.0.26/.stamp_built' failed
> > > make[1]: *** [/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built] Error 2
> > > Makefile:88: recipe for target '_all' failed
> > > make: *** [_all] Error 2
> > > make: Leaving directory '/home/buildroot/autobuild/run/instance-2/buildroot'
> > > ---------------------------------->8------------------------------------??
> > > 
> > > When with old version we get something like:
> > > ---------------------------------->8------------------------------------??
> > > make[2]: *** [cgiedit.o] Error 1
> > > make[1]: *** [/home/buildroot/autobuild/run/instance-1/output/build/privoxy-3.0.26/.stamp_built] Error 2
> > > make: *** [_all] Error 2
> > > make: Leaving directory `/home/buildroot/autobuild/run/instance-1/buildroot'
> > > ---------------------------------->8------------------------------------??
> > > 
> > > So latest make produce much more "noise" and we have to analyze
> > > at least 4 last lines of log to be sure that they contain a line
> > > with failure reason.
> > > 
> > > Signed-off-by: Vlad Zakharov <vzakhar@synopsys.com>
> > 
> > I'm a little bit worried about this change, because we did a fairly
> > similar change in commit 585358277b80dfe18b17b13035675bfe7db48b20,
> > which I quickly reverted in commit
> > a616a8c592caf2a9c9ce82ac1cac9681775452d3 because it was breaking
> > everything. Following 585358277b80dfe18b17b13035675bfe7db48b20, for a
> > large number of builds, the detected build failure was "all" or
> > "all-recursive".
> > 
> > So we really want to be extra careful, by testing the logic change on
> > existing build results first.
> 
> But I haven't updated the regex, only lines count printed by tail.
> The regex suggested by?585358277b80dfe18b17b13035675bfe7db48b20 was able to recognize both
> "make:" and "make[n]:". Note that "all" and "all-recursive" targets appears with the second variant.
> I guess that my changes would not affect failure reason parsing from output of older make versions.
> 
> I can offer another solution:
> We analyze last 4 lines but use the last matched string. As I understand from my experience of analyzing build logs
> the
> string with a real build failure as a rule comes after "all" and "all-recursive".
> 
> > 
> > 
> > Also, another thing that is annoying that we have two places where we
> > calculate the failure reason: in autobuild-run (on the autobuild slave)
> > and in import.inc.php (which runs on autobuild.b.o when an autobuild
> > result is submitted).
> > 
> > Historically, the failure reason was only extracted in import.inc.php,
> > from the submitted log. But later on, some logic was added in
> > autobuild-run to extract the reason, which was used to make sure we
> > keep in build-end.log not just the 500 last lines of the build, but
> > the entire build log from the beginning of the failing package (which
> > requires knowing the package that failed building, and therefore
> > calculating the reason).
> > 
> > It would be great to get rid of this duplication, and have
> > autobuild-run calculate the reason, store it in a "reason" file,
> > submitted to autobuild.b.o as part of the tarball, and import.inc.php
> > simply reads that file. This way we have the reason calculation logic
> > in just one place.
> 
> I can write a separate patch that will exclude duplication and store failure reason in a "reason" file.?
> 
> > 
> > 
> > Thanks,
> > 
> > Thomas
> --?
> Best regards,
> Vlad Zakharov <vzakhar@synopsys.com>
-- 
Best regards,
Vlad Zakharov <vzakhar@synopsys.com>

[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Arnout Vandecappelle]

 Coming back to this old issue...

On 11-11-16 17:04, Vlad Zakharov wrote:
> Hi Thomas, all.
> 
> I strongly believe that something should be done with the issue.
> Of course the approach that I have suggested may not be the best but we can discuss the subject to find better solution.
> It is not a good idea to leave everything as is because failure reason detection totally doesn't work if use up-to-date
> "make" utility. 
> 
> Thank you. 
> 
> On Wed, 2016-10-26 at 12:29 +0000, Vlad Zakharov wrote:
>> Hi Thomas.
>>
>> On Wed, 2016-10-26 at 13:52 +0200, Thomas Petazzoni wrote:
>>>
>>> Hello,
>>>
>>> On Wed, 26 Oct 2016 13:45:17 +0300, Vlad Zakharov wrote:
>>>>
>>>>
>>>> Latest versions of make produce a bit different output than older
>>>> versions do. They also print number of line in Makefile where the
>>>> failure occurred.
>>>>
>>>> E.g. latest make produces the following output:
>>>> ---------------------------------->8------------------------------------  
>>>> GNUmakefile:277: recipe for target 'cgiedit.o' failed
>>>> make[2]: *** [cgiedit.o] Error 1
>>>> package/pkg-generic.mk:201: recipe for target '/home/buildroot/autobuild/run/instance-2/output/build/privoxy-
>>>> 3.0.26/.stamp_built' failed
>>>> make[1]: *** [/home/buildroot/autobuild/run/instance-2/output/build/privoxy-3.0.26/.stamp_built] Error 2
>>>> Makefile:88: recipe for target '_all' failed
>>>> make: *** [_all] Error 2
>>>> make: Leaving directory '/home/buildroot/autobuild/run/instance-2/buildroot'
>>>> ---------------------------------->8------------------------------------  
>>>>
>>>> When with old version we get something like:
>>>> ---------------------------------->8------------------------------------  
>>>> make[2]: *** [cgiedit.o] Error 1
>>>> make[1]: *** [/home/buildroot/autobuild/run/instance-1/output/build/privoxy-3.0.26/.stamp_built] Error 2
>>>> make: *** [_all] Error 2
>>>> make: Leaving directory `/home/buildroot/autobuild/run/instance-1/buildroot'
>>>> ---------------------------------->8------------------------------------  
>>>>
>>>> So latest make produce much more "noise" and we have to analyze
>>>> at least 4 last lines of log to be sure that they contain a line
>>>> with failure reason.

 Instead of relying on make's "noise", why don't we just use the very last line
of build-time.log?


 Regards,
 Arnout

[snip]

-- 
Arnout Vandecappelle                          arnout at mind be
Senior Embedded Software Architect            +32-16-286500
Essensium/Mind                                http://www.mind.be
G.Geenslaan 9, 3001 Leuven, Belgium           BE 872 984 063 RPR Leuven
LinkedIn profile: http://www.linkedin.com/in/arnoutvandecappelle
GPG fingerprint:  7493 020B C7E3 8618 8DEC 222C 82EB F404 F9AC 0DDF

[Buildroot] [PATCH][autobuild] Use last 4 lines of log instead of 3 when getting failure reason

[Thomas Petazzoni]

Hello,

On Sat, 15 Apr 2017 00:48:48 +0200, Arnout Vandecappelle wrote:

>  Instead of relying on make's "noise", why don't we just use the very last line
> of build-time.log?

Good idea. I believe we rely on make noise, because build-time.log
didn't exist when the autobuild-run stuff was initially written.

Thomas
-- 
Thomas Petazzoni, CTO, Free Electrons
Embedded Linux and Kernel engineering
http://free-electrons.com