[OE-core] [PATCH] package_ipk: handle exception for subprocess command

[Andrey Zhizhikin]

On Thu, Apr 25, 2019 at 3:41 PM <richard.purdie at 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 at 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 at 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 at 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 at 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.