[PATCH v2] build: Make python output print to stdout when running with -v (verbose)

[PATCH v2] build: Make python output print to stdout when running with -v (verbose)

[Mark Asselstine]

When tasks are run with -v (verbose) on the bitbake commandline, shell
tasks print their stdout, python tasks do not.

This change redirects the python task's print output to an in memory
buffer. After the task is executed the output is printed to stdout via
the logger. This makes the python task behavior match the shell task
behavior when running with -v. The contents of the task's log files
remain unchanged after this change.

This approach should keep the correct order in most cases, however, if
the python task accesses the logger directly, that content will appear
before other output. On the other hand, this change should negate the
need for python tasks to access the logger directly.

The following example will produce out-of-order output

--
python do_build() {
   import sys
   print("Start")
   print("Oops!", file=sys.stderr)
   bb.plain("********************");
   bb.plain("*                  *");
   bb.plain("*  Hello, World!   *");
   bb.plain("*                  *");
   bb.plain("********************");
   print("Finish")
}
--
will output
--
********************
*                  *
*  Hello, World!   *
*                  *
********************
Start
Oops!
Finish
--

The logging-test.bb in meta-selftest or the above 'hello world!' can
be used to review this change.

[Yocto #14544]

Signed-off-by: Mark Asselstine <mark.asselstine@windriver.com>
---

v2: Richard, per your suggestions, I have added capturing stderr and
also storing and restoring the previous stdout and stderr. Since we
are already flushing stdout and stderr when verboseStdoutLogging I
have skipped the second flushes.

 lib/bb/build.py | 23 +++++++++++++++++++----
 1 file changed, 19 insertions(+), 4 deletions(-)

diff --git a/lib/bb/build.py b/lib/bb/build.py
index 5a172711..786c215c 100644
--- a/lib/bb/build.py
+++ b/lib/bb/build.py
@@ -25,6 +25,7 @@ import bb
 import bb.msg
 import bb.process
 import bb.progress
+from io import StringIO
 from bb import data, event, utils
 
 bblogger = logging.getLogger('BitBake')
@@ -296,13 +297,27 @@ def exec_func_python(func, d, runfile, cwd=None):
         lineno = int(d.getVarFlag(func, "lineno", False))
         bb.methodpool.insert_method(func, text, fn, lineno - 1)
 
+        if verboseStdoutLogging:
+            sys.stdout.flush()
+            sys.stderr.flush()
+            currout = sys.stdout
+            currerr = sys.stderr
+            sys.stderr = sys.stdout = execio = StringIO()
         comp = utils.better_compile(code, func, "exec_func_python() autogenerated")
         utils.better_exec(comp, {"d": d}, code, "exec_func_python() autogenerated")
     finally:
-        # We want any stdout/stderr to be printed before any other log messages to make debugging
-        # more accurate. In some cases we seem to lose stdout/stderr entirely in logging tests without this.
-        sys.stdout.flush()
-        sys.stderr.flush()
+        if verboseStdoutLogging:
+            execio.flush()
+            logger.plain("%s" % execio.getvalue())
+            sys.stdout = currout
+            sys.stderr = currerr
+            execio.close()
+        else:
+            # We want any stdout/stderr to be printed before any other log
+            # messages to make debugging more accurate. In some cases we seem
+            # to lose stdout/stderr entirely in logging tests without this.
+            sys.stdout.flush()
+            sys.stderr.flush()
         bb.debug(2, "Python function %s finished" % func)
 
         if cwd and olddir:
-- 
2.30.2

Re: [bitbake-devel] [PATCH v2] build: Make python output print to stdout when running with -v (verbose)

[Alexandre Belloni]

Hello,

This seems to break bitbake selftests:

https://autobuilder.yoctoproject.org/typhoon/#builders/127/builds/1082/steps/15/logs/stdio
https://autobuilder.yoctoproject.org/typhoon/#builders/80/builds/4859/steps/14/logs/stdio
https://autobuilder.yoctoproject.org/typhoon/#builders/87/builds/4938/steps/14/logs/stdio
https://autobuilder.yoctoproject.org/typhoon/#builders/79/builds/4912/steps/15/logs/stdio
https://autobuilder.yoctoproject.org/typhoon/#builders/86/builds/4903/steps/14/logs/stdio



On 10/03/2023 09:58:42-0500, Mark Asselstine wrote:
> When tasks are run with -v (verbose) on the bitbake commandline, shell
> tasks print their stdout, python tasks do not.
> 
> This change redirects the python task's print output to an in memory
> buffer. After the task is executed the output is printed to stdout via
> the logger. This makes the python task behavior match the shell task
> behavior when running with -v. The contents of the task's log files
> remain unchanged after this change.
> 
> This approach should keep the correct order in most cases, however, if
> the python task accesses the logger directly, that content will appear
> before other output. On the other hand, this change should negate the
> need for python tasks to access the logger directly.
> 
> The following example will produce out-of-order output
> 
> --
> python do_build() {
>    import sys
>    print("Start")
>    print("Oops!", file=sys.stderr)
>    bb.plain("********************");
>    bb.plain("*                  *");
>    bb.plain("*  Hello, World!   *");
>    bb.plain("*                  *");
>    bb.plain("********************");
>    print("Finish")
> }
> --
> will output
> --
> ********************
> *                  *
> *  Hello, World!   *
> *                  *
> ********************
> Start
> Oops!
> Finish
> --
> 
> The logging-test.bb in meta-selftest or the above 'hello world!' can
> be used to review this change.
> 
> [Yocto #14544]
> 
> Signed-off-by: Mark Asselstine <mark.asselstine@windriver.com>
> ---
> 
> v2: Richard, per your suggestions, I have added capturing stderr and
> also storing and restoring the previous stdout and stderr. Since we
> are already flushing stdout and stderr when verboseStdoutLogging I
> have skipped the second flushes.
> 
>  lib/bb/build.py | 23 +++++++++++++++++++----
>  1 file changed, 19 insertions(+), 4 deletions(-)
> 
> diff --git a/lib/bb/build.py b/lib/bb/build.py
> index 5a172711..786c215c 100644
> --- a/lib/bb/build.py
> +++ b/lib/bb/build.py
> @@ -25,6 +25,7 @@ import bb
>  import bb.msg
>  import bb.process
>  import bb.progress
> +from io import StringIO
>  from bb import data, event, utils
>  
>  bblogger = logging.getLogger('BitBake')
> @@ -296,13 +297,27 @@ def exec_func_python(func, d, runfile, cwd=None):
>          lineno = int(d.getVarFlag(func, "lineno", False))
>          bb.methodpool.insert_method(func, text, fn, lineno - 1)
>  
> +        if verboseStdoutLogging:
> +            sys.stdout.flush()
> +            sys.stderr.flush()
> +            currout = sys.stdout
> +            currerr = sys.stderr
> +            sys.stderr = sys.stdout = execio = StringIO()
>          comp = utils.better_compile(code, func, "exec_func_python() autogenerated")
>          utils.better_exec(comp, {"d": d}, code, "exec_func_python() autogenerated")
>      finally:
> -        # We want any stdout/stderr to be printed before any other log messages to make debugging
> -        # more accurate. In some cases we seem to lose stdout/stderr entirely in logging tests without this.
> -        sys.stdout.flush()
> -        sys.stderr.flush()
> +        if verboseStdoutLogging:
> +            execio.flush()
> +            logger.plain("%s" % execio.getvalue())
> +            sys.stdout = currout
> +            sys.stderr = currerr
> +            execio.close()
> +        else:
> +            # We want any stdout/stderr to be printed before any other log
> +            # messages to make debugging more accurate. In some cases we seem
> +            # to lose stdout/stderr entirely in logging tests without this.
> +            sys.stdout.flush()
> +            sys.stderr.flush()
>          bb.debug(2, "Python function %s finished" % func)
>  
>          if cwd and olddir:
> -- 
> 2.30.2
> 

> 
> -=-=-=-=-=-=-=-=-=-=-=-
> Links: You receive all messages sent to this group.
> View/Reply Online (#14538): https://lists.openembedded.org/g/bitbake-devel/message/14538
> Mute This Topic: https://lists.openembedded.org/mt/97520900/3617179
> Group Owner: bitbake-devel+owner@lists.openembedded.org
> Unsubscribe: https://lists.openembedded.org/g/bitbake-devel/unsub [alexandre.belloni@bootlin.com]
> -=-=-=-=-=-=-=-=-=-=-=-
> 


-- 
Alexandre Belloni, co-owner and COO, Bootlin
Embedded Linux and Kernel engineering
https://bootlin.com