* Three copies of output from failing task
@ 2021-03-30 14:30 Mike Crowe
2021-03-30 16:48 ` [bitbake-devel] " Ross Burton
2021-04-06 14:26 ` Richard Purdie
0 siblings, 2 replies; 4+ messages in thread
From: Mike Crowe @ 2021-03-30 14:30 UTC (permalink / raw)
To: bitbake-devel
After upgrading from oe-core Warrior (Bitbake 1.42) to Dunfell (Bitbake
1.46), I'm seeing _three_ copies of the log output for every build failure.
I see similar when using the current state of oe-core master (along with
the new backtraces.)
To reproduce the problem, I hacked openssl_1.1.1k.bb:do_configure to insert:
echo "an error"
false
and ran bitbake openssl-native. The output was:
--8<--
NOTE: Executing Tasks
ERROR: openssl-native-1.1.1k-r0 do_configure: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
an error
WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
WARNING: Backtrace (BB generated script):
#1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
#2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
Backtrace (metadata-relative locations):
#1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
ERROR: Logfile of failure stored in: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/log.do_configure.32031
Log data follows:
| DEBUG: Executing python function extend_recipe_sysroot
| NOTE: Direct dependencies are ['/overflow/mac/nobackup/git/oe-core/meta/recipes-devtools/quilt/quilt-native_0.66.bb:do_populate_sysroot']
| NOTE: Installed into sysroot: []
| NOTE: Skipping as already exists in sysroot: ['quilt-native']
| DEBUG: Python function extend_recipe_sysroot finished
| DEBUG: Executing shell function do_configure
| an error
| WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
| WARNING: Backtrace (BB generated script):
| #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
| #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
| ERROR: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
| an error
| WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
| WARNING: Backtrace (BB generated script):
| #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
| #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
|
| Backtrace (metadata-relative locations):
| #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
ERROR: Task (virtual:native:/overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb:do_configure) failed with exit code '1'
NOTE: Tasks Summary: Attempted 14 tasks of which 13 didn't need to be rerun and 1 failed.
-->8--
Even if I set BBINCLUDELOGS="no", I still get these three copies.
The first one (without the leading "|" characters) appears to come from
_build.py:_exec_task (around line 702) executing logger.error(str(exc)).
This line dates from 2011.
The second and third ones (with the leading "|") come from knotty.py around
line 767. They are both in log.do_configure.32031. It looks like the third
copy is coming from the same place as the first copy, but has been written
to both the console and the log file.
If I comment out the previously-mentioned call to logger.error(str(exc)) in
_build.py:_exec_task then I get the single copy of the task output as I
would expect.
Does anyone know what the proper fix for this might be?
Thanks.
Mike.
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [bitbake-devel] Three copies of output from failing task
2021-03-30 14:30 Three copies of output from failing task Mike Crowe
@ 2021-03-30 16:48 ` Ross Burton
2021-04-06 14:26 ` Richard Purdie
1 sibling, 0 replies; 4+ messages in thread
From: Ross Burton @ 2021-03-30 16:48 UTC (permalink / raw)
To: yocto; +Cc: bitbake-devel
This has been bugging me for some time, so I'm keen for you to fix this. :)
Ross
On Tue, 30 Mar 2021 at 15:30, Mike Crowe via lists.openembedded.org
<yocto=mac.mcrowe.com@lists.openembedded.org> wrote:
>
> After upgrading from oe-core Warrior (Bitbake 1.42) to Dunfell (Bitbake
> 1.46), I'm seeing _three_ copies of the log output for every build failure.
> I see similar when using the current state of oe-core master (along with
> the new backtraces.)
>
> To reproduce the problem, I hacked openssl_1.1.1k.bb:do_configure to insert:
>
> echo "an error"
> false
>
> and ran bitbake openssl-native. The output was:
>
> --8<--
> NOTE: Executing Tasks
> ERROR: openssl-native-1.1.1k-r0 do_configure: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
> an error
> WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> WARNING: Backtrace (BB generated script):
> #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
>
> Backtrace (metadata-relative locations):
> #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
> ERROR: Logfile of failure stored in: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/log.do_configure.32031
> Log data follows:
> | DEBUG: Executing python function extend_recipe_sysroot
> | NOTE: Direct dependencies are ['/overflow/mac/nobackup/git/oe-core/meta/recipes-devtools/quilt/quilt-native_0.66.bb:do_populate_sysroot']
> | NOTE: Installed into sysroot: []
> | NOTE: Skipping as already exists in sysroot: ['quilt-native']
> | DEBUG: Python function extend_recipe_sysroot finished
> | DEBUG: Executing shell function do_configure
> | an error
> | WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> | WARNING: Backtrace (BB generated script):
> | #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> | #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> | ERROR: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
> | an error
> | WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> | WARNING: Backtrace (BB generated script):
> | #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> | #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> |
> | Backtrace (metadata-relative locations):
> | #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
> ERROR: Task (virtual:native:/overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb:do_configure) failed with exit code '1'
> NOTE: Tasks Summary: Attempted 14 tasks of which 13 didn't need to be rerun and 1 failed.
> -->8--
>
> Even if I set BBINCLUDELOGS="no", I still get these three copies.
>
> The first one (without the leading "|" characters) appears to come from
> _build.py:_exec_task (around line 702) executing logger.error(str(exc)).
> This line dates from 2011.
>
> The second and third ones (with the leading "|") come from knotty.py around
> line 767. They are both in log.do_configure.32031. It looks like the third
> copy is coming from the same place as the first copy, but has been written
> to both the console and the log file.
>
> If I comment out the previously-mentioned call to logger.error(str(exc)) in
> _build.py:_exec_task then I get the single copy of the task output as I
> would expect.
>
> Does anyone know what the proper fix for this might be?
>
> Thanks.
>
> Mike.
>
>
>
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [bitbake-devel] Three copies of output from failing task
2021-03-30 14:30 Three copies of output from failing task Mike Crowe
2021-03-30 16:48 ` [bitbake-devel] " Ross Burton
@ 2021-04-06 14:26 ` Richard Purdie
2021-04-06 14:47 ` Mike Crowe
1 sibling, 1 reply; 4+ messages in thread
From: Richard Purdie @ 2021-04-06 14:26 UTC (permalink / raw)
To: yocto, bitbake-devel
On Tue, 2021-03-30 at 15:30 +0100, Mike Crowe via lists.openembedded.org wrote:
> After upgrading from oe-core Warrior (Bitbake 1.42) to Dunfell (Bitbake
> 1.46), I'm seeing _three_ copies of the log output for every build failure.
> I see similar when using the current state of oe-core master (along with
> the new backtraces.)
>
> To reproduce the problem, I hacked openssl_1.1.1k.bb:do_configure to insert:
>
> echo "an error"
> false
>
> and ran bitbake openssl-native. The output was:
>
> --8<--
> NOTE: Executing Tasks
> ERROR: openssl-native-1.1.1k-r0 do_configure: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
> an error
> WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> WARNING: Backtrace (BB generated script):
> #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
>
> Backtrace (metadata-relative locations):
> #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
> ERROR: Logfile of failure stored in: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/log.do_configure.32031
> Log data follows:
> > DEBUG: Executing python function extend_recipe_sysroot
> > NOTE: Direct dependencies are ['/overflow/mac/nobackup/git/oe-core/meta/recipes-devtools/quilt/quilt-native_0.66.bb:do_populate_sysroot']
> > NOTE: Installed into sysroot: []
> > NOTE: Skipping as already exists in sysroot: ['quilt-native']
> > DEBUG: Python function extend_recipe_sysroot finished
> > DEBUG: Executing shell function do_configure
> > an error
> > WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> > WARNING: Backtrace (BB generated script):
> > #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> > #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> > ERROR: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
> > an error
> > WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> > WARNING: Backtrace (BB generated script):
> > #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> > #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> >
> > Backtrace (metadata-relative locations):
> > #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
> ERROR: Task (virtual:native:/overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb:do_configure) failed with exit code '1'
> NOTE: Tasks Summary: Attempted 14 tasks of which 13 didn't need to be rerun and 1 failed.
> -->8--
>
> Even if I set BBINCLUDELOGS="no", I still get these three copies.
>
> The first one (without the leading "|" characters) appears to come from
> _build.py:_exec_task (around line 702) executing logger.error(str(exc)).
> This line dates from 2011.
>
> The second and third ones (with the leading "|") come from knotty.py around
> line 767. They are both in log.do_configure.32031. It looks like the third
> copy is coming from the same place as the first copy, but has been written
> to both the console and the log file.
>
> If I comment out the previously-mentioned call to logger.error(str(exc)) in
> _build.py:_exec_task then I get the single copy of the task output as I
> would expect.
>
> Does anyone know what the proper fix for this might be?
Thanks for the report and analysis. I think we should do something about it
but having stared at the code a bit, I'm still not entirely sure what. I think
the trouble is the error is being reported at mutliple levels in the code
and we;re a bit paranoid about doing that as there is nothing worse than
a failure where the traceback isn't shown.
I'll have to stare at it a bit more but wanted you to know I've at least
looked at it and agree we should try and do something...
Cheers,
Richard
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [bitbake-devel] Three copies of output from failing task
2021-04-06 14:26 ` Richard Purdie
@ 2021-04-06 14:47 ` Mike Crowe
0 siblings, 0 replies; 4+ messages in thread
From: Mike Crowe @ 2021-04-06 14:47 UTC (permalink / raw)
To: Richard Purdie; +Cc: bitbake-devel
On Tuesday 06 April 2021 at 15:26:02 +0100, Richard Purdie wrote:
> On Tue, 2021-03-30 at 15:30 +0100, Mike Crowe via lists.openembedded.org wrote:
> > After upgrading from oe-core Warrior (Bitbake 1.42) to Dunfell (Bitbake
> > 1.46), I'm seeing _three_ copies of the log output for every build failure.
> > I see similar when using the current state of oe-core master (along with
> > the new backtraces.)
> >
> > To reproduce the problem, I hacked openssl_1.1.1k.bb:do_configure to insert:
> >
> > echo "an error"
> > false
> >
> > and ran bitbake openssl-native. The output was:
> >
> > --8<--
> > NOTE: Executing Tasks
> > ERROR: openssl-native-1.1.1k-r0 do_configure: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
> > an error
> > WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> > WARNING: Backtrace (BB generated script):
> > #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> > #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> >
> > Backtrace (metadata-relative locations):
> > #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
> > ERROR: Logfile of failure stored in: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/log.do_configure.32031
> > Log data follows:
> > > DEBUG: Executing python function extend_recipe_sysroot
> > > NOTE: Direct dependencies are ['/overflow/mac/nobackup/git/oe-core/meta/recipes-devtools/quilt/quilt-native_0.66.bb:do_populate_sysroot']
> > > NOTE: Installed into sysroot: []
> > > NOTE: Skipping as already exists in sysroot: ['quilt-native']
> > > DEBUG: Python function extend_recipe_sysroot finished
> > > DEBUG: Executing shell function do_configure
> > > an error
> > > WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> > > WARNING: Backtrace (BB generated script):
> > > #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> > > #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> > > ERROR: Execution of '/overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031' failed with exit code 1:
> > > an error
> > > WARNING: /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031:143 exit 1 from 'false'
> > > WARNING: Backtrace (BB generated script):
> > > #1: do_configure, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 143
> > > #2: main, /overflow/mac/nobackup/git/oe-core/build/tmp-glibc/work/x86_64-linux/openssl-native/1.1.1k-r0/temp/run.do_configure.32031, line 221
> > >
> > > Backtrace (metadata-relative locations):
> > > #1: do_configure, /overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb, line 78
> > ERROR: Task (virtual:native:/overflow/mac/nobackup/git/oe-core/meta/recipes-connectivity/openssl/openssl_1.1.1k.bb:do_configure) failed with exit code '1'
> > NOTE: Tasks Summary: Attempted 14 tasks of which 13 didn't need to be rerun and 1 failed.
> > -->8--
> >
> > Even if I set BBINCLUDELOGS="no", I still get these three copies.
> >
> > The first one (without the leading "|" characters) appears to come from
> > _build.py:_exec_task (around line 702) executing logger.error(str(exc)).
> > This line dates from 2011.
> >
> > The second and third ones (with the leading "|") come from knotty.py around
> > line 767. They are both in log.do_configure.32031. It looks like the third
> > copy is coming from the same place as the first copy, but has been written
> > to both the console and the log file.
> >
> > If I comment out the previously-mentioned call to logger.error(str(exc)) in
> > _build.py:_exec_task then I get the single copy of the task output as I
> > would expect.
> >
> > Does anyone know what the proper fix for this might be?
>
> Thanks for the report and analysis. I think we should do something about it
> but having stared at the code a bit, I'm still not entirely sure what. I think
> the trouble is the error is being reported at mutliple levels in the code
> and we;re a bit paranoid about doing that as there is nothing worse than
> a failure where the traceback isn't shown.
>
> I'll have to stare at it a bit more but wanted you to know I've at least
> looked at it and agree we should try and do something...
Thanks for looking at it. I did plan to try to dig further into it after
Ross's response, but haven't had a chance yet. If even you're not sure what
the right thing to do is then I don't have any great hopes that I'll be
able to solve it!
Thanks.
Mike.
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2021-04-06 14:47 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2021-03-30 14:30 Three copies of output from failing task Mike Crowe
2021-03-30 16:48 ` [bitbake-devel] " Ross Burton
2021-04-06 14:26 ` Richard Purdie
2021-04-06 14:47 ` Mike Crowe
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.