[PATCH] package_ipk: handle exception for subprocess command

[PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

When opkg-build command fails to execute, subprocess is returned with
exception instead of printing to stderr. This causes the error logging
not to be printed out, as the "finally" statement does not contain any
bitbake error output.

One example of this behavior is when the package name contains uppercase
character, which are rejected by opkg-build, subprocess.check_output
would except and no error log would be produced.

This commit catches the exception subprocess.CalledProcessError and
produces bb.error output visible to the user.

Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
---
 meta/classes/package_ipk.bbclass | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/meta/classes/package_ipk.bbclass b/meta/classes/package_ipk.bbclass
index d1b317b42b..f181f5b4fd 100644
--- a/meta/classes/package_ipk.bbclass
+++ b/meta/classes/package_ipk.bbclass
@@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
             ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir, pkgname, ipkver, d.getVar('PACKAGE_ARCH'))
             sign_ipk(d, ipk_to_sign)
 
+    except subprocess.CalledProcessError as exc:
+        bb.error("OPKG Build failed: %s" % exc.output)
     finally:
         cleanupcontrol(root)
         bb.utils.unlockfile(lf)
-- 
2.17.1

Re: [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

Ping.

On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <andrey.z@gmail.com> wrote:
>
> When opkg-build command fails to execute, subprocess is returned with
> exception instead of printing to stderr. This causes the error logging
> not to be printed out, as the "finally" statement does not contain any
> bitbake error output.
>
> One example of this behavior is when the package name contains uppercase
> character, which are rejected by opkg-build, subprocess.check_output
> would except and no error log would be produced.
>
> This commit catches the exception subprocess.CalledProcessError and
> produces bb.error output visible to the user.
>
> Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> ---
>  meta/classes/package_ipk.bbclass | 2 ++
>  1 file changed, 2 insertions(+)
>
> diff --git a/meta/classes/package_ipk.bbclass b/meta/classes/package_ipk.bbclass
> index d1b317b42b..f181f5b4fd 100644
> --- a/meta/classes/package_ipk.bbclass
> +++ b/meta/classes/package_ipk.bbclass
> @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
>              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir, pkgname, ipkver, d.getVar('PACKAGE_ARCH'))
>              sign_ipk(d, ipk_to_sign)
>
> +    except subprocess.CalledProcessError as exc:
> +        bb.error("OPKG Build failed: %s" % exc.output)
>      finally:
>          cleanupcontrol(root)
>          bb.utils.unlockfile(lf)
> --
> 2.17.1
>

Re: [PATCH] package_ipk: handle exception for subprocess command

[Richard Purdie]

On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> Ping.
> 
> On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <andrey.z@gmail.com
> > wrote:
> > When opkg-build command fails to execute, subprocess is returned
> > with
> > exception instead of printing to stderr. This causes the error
> > logging
> > not to be printed out, as the "finally" statement does not contain
> > any
> > bitbake error output.
> > 
> > One example of this behavior is when the package name contains
> > uppercase
> > character, which are rejected by opkg-build,
> > subprocess.check_output
> > would except and no error log would be produced.
> > 
> > This commit catches the exception subprocess.CalledProcessError and
> > produces bb.error output visible to the user.
> > 
> > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > ---
> >  meta/classes/package_ipk.bbclass | 2 ++
> >  1 file changed, 2 insertions(+)
> > 
> > diff --git a/meta/classes/package_ipk.bbclass
> > b/meta/classes/package_ipk.bbclass
> > index d1b317b42b..f181f5b4fd 100644
> > --- a/meta/classes/package_ipk.bbclass
> > +++ b/meta/classes/package_ipk.bbclass
> > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir, pkgname,
> > ipkver, d.getVar('PACKAGE_ARCH'))
> >              sign_ipk(d, ipk_to_sign)
> > 
> > +    except subprocess.CalledProcessError as exc:
> > +        bb.error("OPKG Build failed: %s" % exc.output)
> >      finally:
> >          cleanupcontrol(root)
> >          bb.utils.unlockfile(lf)

My main concern is why isn't the raised exception being caught and
causing its own error...

This feels like a workaround rather than fixing the underlying problem
which I suspect might be in the parallel execution code exception
handling.

Cheers,

Richard

Re: [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

On Mon, Apr 15, 2019 at 6:45 PM Richard Purdie
<richard.purdie@linuxfoundation.org> wrote:
>
> On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> > Ping.
> >
> > On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <andrey.z@gmail.com
> > > wrote:
> > > When opkg-build command fails to execute, subprocess is returned
> > > with
> > > exception instead of printing to stderr. This causes the error
> > > logging
> > > not to be printed out, as the "finally" statement does not contain
> > > any
> > > bitbake error output.
> > >
> > > One example of this behavior is when the package name contains
> > > uppercase
> > > character, which are rejected by opkg-build,
> > > subprocess.check_output
> > > would except and no error log would be produced.
> > >
> > > This commit catches the exception subprocess.CalledProcessError and
> > > produces bb.error output visible to the user.
> > >
> > > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > > ---
> > >  meta/classes/package_ipk.bbclass | 2 ++
> > >  1 file changed, 2 insertions(+)
> > >
> > > diff --git a/meta/classes/package_ipk.bbclass
> > > b/meta/classes/package_ipk.bbclass
> > > index d1b317b42b..f181f5b4fd 100644
> > > --- a/meta/classes/package_ipk.bbclass
> > > +++ b/meta/classes/package_ipk.bbclass
> > > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> > >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir, pkgname,
> > > ipkver, d.getVar('PACKAGE_ARCH'))
> > >              sign_ipk(d, ipk_to_sign)
> > >
> > > +    except subprocess.CalledProcessError as exc:
> > > +        bb.error("OPKG Build failed: %s" % exc.output)
> > >      finally:
> > >          cleanupcontrol(root)
> > >          bb.utils.unlockfile(lf)
>
> My main concern is why isn't the raised exception being caught and
> causing its own error...

The raised exception is actually caught by a finally: statement below,
and the build gracefully terminates. The problem is that finally:
block does not contain any valuable output to inform user what
actually happened.
subprocess.check_output() would throw this exception every time the
command in sub-process is terminated with the error code, and since we
do tell it to dump stderr -> stdout - the error message would be
contained in the exception output.
This additional handling of the subprocess.check_output() exception
would extract the stdout from the failed process here and just shows
to the user the actual output from command processing, so that he is
aware what was wrong.

The case where I personally needed it the most is when the package
name contained upper and lower case characters, which were rejected by
the opkg-build command and until I introduced the handler - I just had
an erroneous build failure without any additional information on what
went wrong.

>
> This feels like a workaround rather than fixing the underlying problem
> which I suspect might be in the parallel execution code exception
> handling.
The exception from  subprocess.check_output() is actually expected and
perfectly handled, so there is no problem with that. This patch would
just deliver a bit more information in the output for user to react
proper.
>
> Cheers,
>
> Richard
>
>

-- 
Regards,
Andrey.

Re: [PATCH] package_ipk: handle exception for subprocess command

[richard.purdie]

On Tue, 2019-04-16 at 09:10 +0200, Andrey Zhizhikin wrote:
> On Mon, Apr 15, 2019 at 6:45 PM Richard Purdie
> <richard.purdie@linuxfoundation.org> wrote:
> > On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> > > Ping.
> > > 
> > > On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <
> > > andrey.z@gmail.com
> > > > wrote:
> > > > When opkg-build command fails to execute, subprocess is
> > > > returned
> > > > with
> > > > exception instead of printing to stderr. This causes the error
> > > > logging
> > > > not to be printed out, as the "finally" statement does not
> > > > contain
> > > > any
> > > > bitbake error output.
> > > > 
> > > > One example of this behavior is when the package name contains
> > > > uppercase
> > > > character, which are rejected by opkg-build,
> > > > subprocess.check_output
> > > > would except and no error log would be produced.
> > > > 
> > > > This commit catches the exception subprocess.CalledProcessError
> > > > and
> > > > produces bb.error output visible to the user.
> > > > 
> > > > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > > > ---
> > > >  meta/classes/package_ipk.bbclass | 2 ++
> > > >  1 file changed, 2 insertions(+)
> > > > 
> > > > diff --git a/meta/classes/package_ipk.bbclass
> > > > b/meta/classes/package_ipk.bbclass
> > > > index d1b317b42b..f181f5b4fd 100644
> > > > --- a/meta/classes/package_ipk.bbclass
> > > > +++ b/meta/classes/package_ipk.bbclass
> > > > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> > > >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir,
> > > > pkgname,
> > > > ipkver, d.getVar('PACKAGE_ARCH'))
> > > >              sign_ipk(d, ipk_to_sign)
> > > > 
> > > > +    except subprocess.CalledProcessError as exc:
> > > > +        bb.error("OPKG Build failed: %s" % exc.output)
> > > >      finally:
> > > >          cleanupcontrol(root)
> > > >          bb.utils.unlockfile(lf)
> > 
> > My main concern is why isn't the raised exception being caught and
> > causing its own error...
> 
> The raised exception is actually caught by a finally: statement
> below, and the build gracefully terminates. The problem is that
> finally: block does not contain any valuable output to inform user
> what actually happened.

This isn't how python works. The exception should be "re-raised after
the finally clause has been executed" to quote the python manual:
https://docs.python.org/3/tutorial/errors.html#defining-clean-up-actions

> subprocess.check_output() would throw this exception every time the
> command in sub-process is terminated with the error code, and since
> we
> do tell it to dump stderr -> stdout - the error message would be
> contained in the exception output.
> This additional handling of the subprocess.check_output() exception
> would extract the stdout from the failed process here and just shows
> to the user the actual output from command processing, so that he is
> aware what was wrong.
> 
> The case where I personally needed it the most is when the package
> name contained upper and lower case characters, which were rejected
> by
> the opkg-build command and until I introduced the handler - I just
> had
> an erroneous build failure without any additional information on what
> went wrong.
> 
> > This feels like a workaround rather than fixing the underlying
> > problem
> > which I suspect might be in the parallel execution code exception
> > handling.
> The exception from  subprocess.check_output() is actually expected
> and
> perfectly handled, so there is no problem with that. This patch would
> just deliver a bit more information in the output for user to react
> proper.


See my comment above, the finally should not be blocking this exception
from being raised...

Cheers,

Richard

Re: [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

On Tue, Apr 16, 2019 at 10:24 AM <richard.purdie@linuxfoundation.org> wrote:
>
> On Tue, 2019-04-16 at 09:10 +0200, Andrey Zhizhikin wrote:
> > On Mon, Apr 15, 2019 at 6:45 PM Richard Purdie
> > <richard.purdie@linuxfoundation.org> wrote:
> > > On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> > > > Ping.
> > > >
> > > > On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <
> > > > andrey.z@gmail.com
> > > > > wrote:
> > > > > When opkg-build command fails to execute, subprocess is
> > > > > returned
> > > > > with
> > > > > exception instead of printing to stderr. This causes the error
> > > > > logging
> > > > > not to be printed out, as the "finally" statement does not
> > > > > contain
> > > > > any
> > > > > bitbake error output.
> > > > >
> > > > > One example of this behavior is when the package name contains
> > > > > uppercase
> > > > > character, which are rejected by opkg-build,
> > > > > subprocess.check_output
> > > > > would except and no error log would be produced.
> > > > >
> > > > > This commit catches the exception subprocess.CalledProcessError
> > > > > and
> > > > > produces bb.error output visible to the user.
> > > > >
> > > > > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > > > > ---
> > > > >  meta/classes/package_ipk.bbclass | 2 ++
> > > > >  1 file changed, 2 insertions(+)
> > > > >
> > > > > diff --git a/meta/classes/package_ipk.bbclass
> > > > > b/meta/classes/package_ipk.bbclass
> > > > > index d1b317b42b..f181f5b4fd 100644
> > > > > --- a/meta/classes/package_ipk.bbclass
> > > > > +++ b/meta/classes/package_ipk.bbclass
> > > > > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> > > > >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir,
> > > > > pkgname,
> > > > > ipkver, d.getVar('PACKAGE_ARCH'))
> > > > >              sign_ipk(d, ipk_to_sign)
> > > > >
> > > > > +    except subprocess.CalledProcessError as exc:
> > > > > +        bb.error("OPKG Build failed: %s" % exc.output)
> > > > >      finally:
> > > > >          cleanupcontrol(root)
> > > > >          bb.utils.unlockfile(lf)
> > >
> > > My main concern is why isn't the raised exception being caught and
> > > causing its own error...
> >
> > The raised exception is actually caught by a finally: statement
> > below, and the build gracefully terminates. The problem is that
> > finally: block does not contain any valuable output to inform user
> > what actually happened.
>
> This isn't how python works. The exception should be "re-raised after
> the finally clause has been executed" to quote the python manual:
> https://docs.python.org/3/tutorial/errors.html#defining-clean-up-actions
>

Sorry, I guess my previous reply was a bit confusing.. I agree, the
exception would not be blocked by finally: statement, and this is why
the build gracefully shuts down. What the finally: block does not
contain is an bb.error() which would provide more information about
the source of error return from subprocess.check_output(). In case if
this patch is applied - exception would be handled and not propagated
further.

Can you please advise whether there would another "raise" statement be
needed after bb.error in the patch, so that in addition to the
subprocess output user would get an entire callstack (like in the case
when subprocess.CalledProcessError was not handled). Currently, with
this patch user would receive the build error with the error string
output from subprocess.check_output().

Thanks a lot!

> > subprocess.check_output() would throw this exception every time the
> > command in sub-process is terminated with the error code, and since
> > we
> > do tell it to dump stderr -> stdout - the error message would be
> > contained in the exception output.
> > This additional handling of the subprocess.check_output() exception
> > would extract the stdout from the failed process here and just shows
> > to the user the actual output from command processing, so that he is
> > aware what was wrong.
> >
> > The case where I personally needed it the most is when the package
> > name contained upper and lower case characters, which were rejected
> > by
> > the opkg-build command and until I introduced the handler - I just
> > had
> > an erroneous build failure without any additional information on what
> > went wrong.
> >
> > > This feels like a workaround rather than fixing the underlying
> > > problem
> > > which I suspect might be in the parallel execution code exception
> > > handling.
> > The exception from  subprocess.check_output() is actually expected
> > and
> > perfectly handled, so there is no problem with that. This patch would
> > just deliver a bit more information in the output for user to react
> > proper.
>
>
> See my comment above, the finally should not be blocking this exception
> from being raised...
>
> Cheers,
>
> Richard
>

-- 
Regards,
Andrey.

Re: [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

Hello Richard,

On Tue, Apr 16, 2019 at 11:12 AM Andrey Zhizhikin <andrey.z@gmail.com> wrote:
>
> On Tue, Apr 16, 2019 at 10:24 AM <richard.purdie@linuxfoundation.org> wrote:
> >
> > On Tue, 2019-04-16 at 09:10 +0200, Andrey Zhizhikin wrote:
> > > On Mon, Apr 15, 2019 at 6:45 PM Richard Purdie
> > > <richard.purdie@linuxfoundation.org> wrote:
> > > > On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> > > > > Ping.
> > > > >
> > > > > On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <
> > > > > andrey.z@gmail.com
> > > > > > wrote:
> > > > > > When opkg-build command fails to execute, subprocess is
> > > > > > returned
> > > > > > with
> > > > > > exception instead of printing to stderr. This causes the error
> > > > > > logging
> > > > > > not to be printed out, as the "finally" statement does not
> > > > > > contain
> > > > > > any
> > > > > > bitbake error output.
> > > > > >
> > > > > > One example of this behavior is when the package name contains
> > > > > > uppercase
> > > > > > character, which are rejected by opkg-build,
> > > > > > subprocess.check_output
> > > > > > would except and no error log would be produced.
> > > > > >
> > > > > > This commit catches the exception subprocess.CalledProcessError
> > > > > > and
> > > > > > produces bb.error output visible to the user.
> > > > > >
> > > > > > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > > > > > ---
> > > > > >  meta/classes/package_ipk.bbclass | 2 ++
> > > > > >  1 file changed, 2 insertions(+)
> > > > > >
> > > > > > diff --git a/meta/classes/package_ipk.bbclass
> > > > > > b/meta/classes/package_ipk.bbclass
> > > > > > index d1b317b42b..f181f5b4fd 100644
> > > > > > --- a/meta/classes/package_ipk.bbclass
> > > > > > +++ b/meta/classes/package_ipk.bbclass
> > > > > > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> > > > > >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir,
> > > > > > pkgname,
> > > > > > ipkver, d.getVar('PACKAGE_ARCH'))
> > > > > >              sign_ipk(d, ipk_to_sign)
> > > > > >
> > > > > > +    except subprocess.CalledProcessError as exc:
> > > > > > +        bb.error("OPKG Build failed: %s" % exc.output)
> > > > > >      finally:
> > > > > >          cleanupcontrol(root)
> > > > > >          bb.utils.unlockfile(lf)
> > > >
> > > > My main concern is why isn't the raised exception being caught and
> > > > causing its own error...
> > >
> > > The raised exception is actually caught by a finally: statement
> > > below, and the build gracefully terminates. The problem is that
> > > finally: block does not contain any valuable output to inform user
> > > what actually happened.
> >
> > This isn't how python works. The exception should be "re-raised after
> > the finally clause has been executed" to quote the python manual:
> > https://docs.python.org/3/tutorial/errors.html#defining-clean-up-actions
> >
>
> Sorry, I guess my previous reply was a bit confusing.. I agree, the
> exception would not be blocked by finally: statement, and this is why
> the build gracefully shuts down. What the finally: block does not
> contain is an bb.error() which would provide more information about
> the source of error return from subprocess.check_output(). In case if
> this patch is applied - exception would be handled and not propagated
> further.
>
> Can you please advise whether there would another "raise" statement be
> needed after bb.error in the patch, so that in addition to the
> subprocess output user would get an entire callstack (like in the case
> when subprocess.CalledProcessError was not handled). Currently, with
> this patch user would receive the build error with the error string
> output from subprocess.check_output().
>
> Thanks a lot!

Can we follow-up on this patch? I'd really appreciate if you can
comment on my points here...

Thanks a lot!

>
> > > subprocess.check_output() would throw this exception every time the
> > > command in sub-process is terminated with the error code, and since
> > > we
> > > do tell it to dump stderr -> stdout - the error message would be
> > > contained in the exception output.
> > > This additional handling of the subprocess.check_output() exception
> > > would extract the stdout from the failed process here and just shows
> > > to the user the actual output from command processing, so that he is
> > > aware what was wrong.
> > >
> > > The case where I personally needed it the most is when the package
> > > name contained upper and lower case characters, which were rejected
> > > by
> > > the opkg-build command and until I introduced the handler - I just
> > > had
> > > an erroneous build failure without any additional information on what
> > > went wrong.
> > >
> > > > This feels like a workaround rather than fixing the underlying
> > > > problem
> > > > which I suspect might be in the parallel execution code exception
> > > > handling.
> > > The exception from  subprocess.check_output() is actually expected
> > > and
> > > perfectly handled, so there is no problem with that. This patch would
> > > just deliver a bit more information in the output for user to react
> > > proper.
> >
> >
> > See my comment above, the finally should not be blocking this exception
> > from being raised...
> >
> > Cheers,
> >
> > Richard
> >
>
> --
> Regards,
> Andrey.

--
Regards,
Andrey.

Re: [PATCH] package_ipk: handle exception for subprocess command

[richard.purdie]

On Tue, 2019-04-16 at 11:12 +0200, Andrey Zhizhikin wrote:
> On Tue, Apr 16, 2019 at 10:24 AM <richard.purdie@linuxfoundation.org>
> wrote:
> > On Tue, 2019-04-16 at 09:10 +0200, Andrey Zhizhikin wrote:
> > > On Mon, Apr 15, 2019 at 6:45 PM Richard Purdie
> > > <richard.purdie@linuxfoundation.org> wrote:
> > > > On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> > > > > Ping.
> > > > > 
> > > > > On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <
> > > > > andrey.z@gmail.com
> > > > > > wrote:
> > > > > > When opkg-build command fails to execute, subprocess is
> > > > > > returned
> > > > > > with
> > > > > > exception instead of printing to stderr. This causes the
> > > > > > error
> > > > > > logging
> > > > > > not to be printed out, as the "finally" statement does not
> > > > > > contain
> > > > > > any
> > > > > > bitbake error output.
> > > > > > 
> > > > > > One example of this behavior is when the package name
> > > > > > contains
> > > > > > uppercase
> > > > > > character, which are rejected by opkg-build,
> > > > > > subprocess.check_output
> > > > > > would except and no error log would be produced.
> > > > > > 
> > > > > > This commit catches the exception
> > > > > > subprocess.CalledProcessError
> > > > > > and
> > > > > > produces bb.error output visible to the user.
> > > > > > 
> > > > > > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > > > > > ---
> > > > > >  meta/classes/package_ipk.bbclass | 2 ++
> > > > > >  1 file changed, 2 insertions(+)
> > > > > > 
> > > > > > diff --git a/meta/classes/package_ipk.bbclass
> > > > > > b/meta/classes/package_ipk.bbclass
> > > > > > index d1b317b42b..f181f5b4fd 100644
> > > > > > --- a/meta/classes/package_ipk.bbclass
> > > > > > +++ b/meta/classes/package_ipk.bbclass
> > > > > > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> > > > > >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir,
> > > > > > pkgname,
> > > > > > ipkver, d.getVar('PACKAGE_ARCH'))
> > > > > >              sign_ipk(d, ipk_to_sign)
> > > > > > 
> > > > > > +    except subprocess.CalledProcessError as exc:
> > > > > > +        bb.error("OPKG Build failed: %s" % exc.output)
> > > > > >      finally:
> > > > > >          cleanupcontrol(root)
> > > > > >          bb.utils.unlockfile(lf)
> > > > 
> > > > My main concern is why isn't the raised exception being caught
> > > > and
> > > > causing its own error...
> > > 
> > > The raised exception is actually caught by a finally: statement
> > > below, and the build gracefully terminates. The problem is that
> > > finally: block does not contain any valuable output to inform
> > > user
> > > what actually happened.
> > 
> > This isn't how python works. The exception should be "re-raised
> > after
> > the finally clause has been executed" to quote the python manual:
> > https://docs.python.org/3/tutorial/errors.html#defining-clean-up-actions
> > 
> 
> Sorry, I guess my previous reply was a bit confusing.. I agree, the
> exception would not be blocked by finally: statement, and this is why
> the build gracefully shuts down. What the finally: block does not
> contain is an bb.error() which would provide more information about
> the source of error return from subprocess.check_output(). In case if
> this patch is applied - exception would be handled and not propagated
> further.
> 
> Can you please advise whether there would another "raise" statement
> be
> needed after bb.error in the patch, so that in addition to the
> subprocess output user would get an entire callstack (like in the
> case
> when subprocess.CalledProcessError was not handled). Currently, with
> this patch user would receive the build error with the error string
> output from subprocess.check_output().

My worry is that we're making a special case fix and for example the
other package back ends could have a similar problem (or any other
users of multiprocess_launch).

I already think subprocess in python is a bit broken as it should share
e.output if its present in an exception. We already special case that
in bitbake, the problem here is that our special case code doesn't
catch this.

Whilst still ugly, perhaps a better fix might be:

diff --git a/meta/lib/oe/utils.py b/meta/lib/oe/utils.py
index a4fd79ccb21..59251810d43 100644
--- a/meta/lib/oe/utils.py
+++ b/meta/lib/oe/utils.py
@@ -324,7 +324,12 @@ def multiprocess_launch(target, items, d, extraargs=None):
     if errors:
         msg = ""
         for (e, tb) in errors:
-            msg = msg + str(e) + ": " + str(tb) + "\n"
+            if isinstance(e, subprocess.CalledProcessError) and e.output:
+                msg = msg + str(e) + "\n"
+                msg = msg + "Subprocess output:"
+                msg = msg + e.output.decode("utf-8", errors="ignore")
+            else:
+                msg = msg + str(e) + ": " + str(tb) + "\n"
         bb.fatal("Fatal errors occurred in subprocesses:\n%s" % msg)
     return results
 

which I think from some local testing gives better output and would
solve your concern and some of mine?

Cheers,

Richard

Re: [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

On Thu, Apr 25, 2019 at 3:41 PM <richard.purdie@linuxfoundation.org> wrote:
>
> On Tue, 2019-04-16 at 11:12 +0200, Andrey Zhizhikin wrote:
> > On Tue, Apr 16, 2019 at 10:24 AM <richard.purdie@linuxfoundation.org>
> > wrote:
> > > On Tue, 2019-04-16 at 09:10 +0200, Andrey Zhizhikin wrote:
> > > > On Mon, Apr 15, 2019 at 6:45 PM Richard Purdie
> > > > <richard.purdie@linuxfoundation.org> wrote:
> > > > > On Sun, 2019-04-14 at 16:21 +0200, Andrey Zhizhikin wrote:
> > > > > > Ping.
> > > > > >
> > > > > > On Thu, Mar 28, 2019 at 10:47 AM Andrey Zhizhikin <
> > > > > > andrey.z@gmail.com
> > > > > > > wrote:
> > > > > > > When opkg-build command fails to execute, subprocess is
> > > > > > > returned
> > > > > > > with
> > > > > > > exception instead of printing to stderr. This causes the
> > > > > > > error
> > > > > > > logging
> > > > > > > not to be printed out, as the "finally" statement does not
> > > > > > > contain
> > > > > > > any
> > > > > > > bitbake error output.
> > > > > > >
> > > > > > > One example of this behavior is when the package name
> > > > > > > contains
> > > > > > > uppercase
> > > > > > > character, which are rejected by opkg-build,
> > > > > > > subprocess.check_output
> > > > > > > would except and no error log would be produced.
> > > > > > >
> > > > > > > This commit catches the exception
> > > > > > > subprocess.CalledProcessError
> > > > > > > and
> > > > > > > produces bb.error output visible to the user.
> > > > > > >
> > > > > > > Signed-off-by: Andrey Zhizhikin <andrey.z@gmail.com>
> > > > > > > ---
> > > > > > >  meta/classes/package_ipk.bbclass | 2 ++
> > > > > > >  1 file changed, 2 insertions(+)
> > > > > > >
> > > > > > > diff --git a/meta/classes/package_ipk.bbclass
> > > > > > > b/meta/classes/package_ipk.bbclass
> > > > > > > index d1b317b42b..f181f5b4fd 100644
> > > > > > > --- a/meta/classes/package_ipk.bbclass
> > > > > > > +++ b/meta/classes/package_ipk.bbclass
> > > > > > > @@ -234,6 +234,8 @@ def ipk_write_pkg(pkg, d):
> > > > > > >              ipk_to_sign = "%s/%s_%s_%s.ipk" % (pkgoutdir,
> > > > > > > pkgname,
> > > > > > > ipkver, d.getVar('PACKAGE_ARCH'))
> > > > > > >              sign_ipk(d, ipk_to_sign)
> > > > > > >
> > > > > > > +    except subprocess.CalledProcessError as exc:
> > > > > > > +        bb.error("OPKG Build failed: %s" % exc.output)
> > > > > > >      finally:
> > > > > > >          cleanupcontrol(root)
> > > > > > >          bb.utils.unlockfile(lf)
> > > > >
> > > > > My main concern is why isn't the raised exception being caught
> > > > > and
> > > > > causing its own error...
> > > >
> > > > The raised exception is actually caught by a finally: statement
> > > > below, and the build gracefully terminates. The problem is that
> > > > finally: block does not contain any valuable output to inform
> > > > user
> > > > what actually happened.
> > >
> > > This isn't how python works. The exception should be "re-raised
> > > after
> > > the finally clause has been executed" to quote the python manual:
> > > https://docs.python.org/3/tutorial/errors.html#defining-clean-up-actions
> > >
> >
> > Sorry, I guess my previous reply was a bit confusing.. I agree, the
> > exception would not be blocked by finally: statement, and this is why
> > the build gracefully shuts down. What the finally: block does not
> > contain is an bb.error() which would provide more information about
> > the source of error return from subprocess.check_output(). In case if
> > this patch is applied - exception would be handled and not propagated
> > further.
> >
> > Can you please advise whether there would another "raise" statement
> > be
> > needed after bb.error in the patch, so that in addition to the
> > subprocess output user would get an entire callstack (like in the
> > case
> > when subprocess.CalledProcessError was not handled). Currently, with
> > this patch user would receive the build error with the error string
> > output from subprocess.check_output().
>
> My worry is that we're making a special case fix and for example the
> other package back ends could have a similar problem (or any other
> users of multiprocess_launch).
>
> I already think subprocess in python is a bit broken as it should share
> e.output if its present in an exception. We already special case that
> in bitbake, the problem here is that our special case code doesn't
> catch this.

Agree, I was also puzzled why there is no valuable output from
subprocess in case exception was raised.

>
> Whilst still ugly, perhaps a better fix might be:
>
> diff --git a/meta/lib/oe/utils.py b/meta/lib/oe/utils.py
> index a4fd79ccb21..59251810d43 100644
> --- a/meta/lib/oe/utils.py
> +++ b/meta/lib/oe/utils.py
> @@ -324,7 +324,12 @@ def multiprocess_launch(target, items, d, extraargs=None):
>      if errors:
>          msg = ""
>          for (e, tb) in errors:
> -            msg = msg + str(e) + ": " + str(tb) + "\n"
> +            if isinstance(e, subprocess.CalledProcessError) and e.output:
> +                msg = msg + str(e) + "\n"
> +                msg = msg + "Subprocess output:"
> +                msg = msg + e.output.decode("utf-8", errors="ignore")
> +            else:
> +                msg = msg + str(e) + ": " + str(tb) + "\n"
>          bb.fatal("Fatal errors occurred in subprocesses:\n%s" % msg)
>      return results
>

Thanks a lot, I'll definitely give it a try! Would you be willing to
take this further in into the master branch?

>
> which I think from some local testing gives better output and would
> solve your concern and some of mine?

That would definitely solve my issue and adhere to my original intention.

-- 
Regards,
Andrey.

Re: [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

On Thu, Apr 25, 2019 at 4:51 PM Andrey Zhizhikin <andrey.z@gmail.com> wrote:
>
> Thanks a lot, I'll definitely give it a try! Would you be willing to
> take this further in into the master branch?

Just saw your other patch against [utils/multiprocess_launch], please
discard this question.

--
Regards,
Andrey.