bitbake-devel.lists.openembedded.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v2] build: Make python output print to stdout when running with -v (verbose)
@ 2023-03-10 14:58 Mark Asselstine
  2023-03-11 23:20 ` [bitbake-devel] " Alexandre Belloni
  0 siblings, 1 reply; 2+ messages in thread
From: Mark Asselstine @ 2023-03-10 14:58 UTC (permalink / raw)
  To: bitbake-devel

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



^ permalink raw reply related	[flat|nested] 2+ messages in thread

* Re: [bitbake-devel] [PATCH v2] build: Make python output print to stdout when running with -v (verbose)
  2023-03-10 14:58 [PATCH v2] build: Make python output print to stdout when running with -v (verbose) Mark Asselstine
@ 2023-03-11 23:20 ` Alexandre Belloni
  0 siblings, 0 replies; 2+ messages in thread
From: Alexandre Belloni @ 2023-03-11 23:20 UTC (permalink / raw)
  To: Mark Asselstine; +Cc: bitbake-devel

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


^ permalink raw reply	[flat|nested] 2+ messages in thread

end of thread, other threads:[~2023-03-11 23:20 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-03-10 14:58 [PATCH v2] build: Make python output print to stdout when running with -v (verbose) Mark Asselstine
2023-03-11 23:20 ` [bitbake-devel] " Alexandre Belloni

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).