bitbake-devel.lists.openembedded.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] build: Make python output print to stdout when running with -v (verbose)
@ 2023-03-09 19:21 Mark Asselstine
  2023-03-09 21:49 ` [bitbake-devel] " Richard Purdie
  0 siblings, 1 reply; 3+ messages in thread
From: Mark Asselstine @ 2023-03-09 19:21 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() {
   print("Start")
   bb.plain("********************");
   bb.plain("*                  *");
   bb.plain("*  Hello, World!   *");
   bb.plain("*                  *");
   bb.plain("********************");
   print("Finish")
}
--
will output
--
********************
*                  *
*  Hello, World!   *
*                  *
********************
Start
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>
---
 lib/bb/build.py | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/lib/bb/build.py b/lib/bb/build.py
index 5a172711..eb2d5b59 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,9 +297,17 @@ 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.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:
+        if verboseStdoutLogging:
+            execio.flush()
+            logger.plain("%s" % execio.getvalue())
+            sys.stdout = sys.__stdout__
+            execio.close()
         # 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()
-- 
2.30.2



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

* Re: [bitbake-devel] [PATCH] build: Make python output print to stdout when running with -v (verbose)
  2023-03-09 19:21 [PATCH] build: Make python output print to stdout when running with -v (verbose) Mark Asselstine
@ 2023-03-09 21:49 ` Richard Purdie
  2023-03-09 21:54   ` Mark Asselstine
  0 siblings, 1 reply; 3+ messages in thread
From: Richard Purdie @ 2023-03-09 21:49 UTC (permalink / raw)
  To: Mark Asselstine, bitbake-devel

On Thu, 2023-03-09 at 14:21 -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() {
>    print("Start")
>    bb.plain("********************");
>    bb.plain("*                  *");
>    bb.plain("*  Hello, World!   *");
>    bb.plain("*                  *");
>    bb.plain("********************");
>    print("Finish")
> }
> --
> will output
> --
> ********************
> *                  *
> *  Hello, World!   *
> *                  *
> ********************
> Start
> 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>
> ---
>  lib/bb/build.py | 9 +++++++++
>  1 file changed, 9 insertions(+)
> 
> diff --git a/lib/bb/build.py b/lib/bb/build.py
> index 5a172711..eb2d5b59 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,9 +297,17 @@ 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.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:
> +        if verboseStdoutLogging:
> +            execio.flush()
> +            logger.plain("%s" % execio.getvalue())
> +            sys.stdout = sys.__stdout__
> +            execio.close()
>          # 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()

From memory, I think exec_func_python can get called recursively so I
suspect this is going to corrupt sys.stdout. You could save it's value,
then restore it?

Also, what about stderr?

Cheers,

Richard



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

* Re: [bitbake-devel] [PATCH] build: Make python output print to stdout when running with -v (verbose)
  2023-03-09 21:49 ` [bitbake-devel] " Richard Purdie
@ 2023-03-09 21:54   ` Mark Asselstine
  0 siblings, 0 replies; 3+ messages in thread
From: Mark Asselstine @ 2023-03-09 21:54 UTC (permalink / raw)
  To: Richard Purdie, bitbake-devel



On 3/9/2023 4:49 PM, Richard Purdie wrote:
> On Thu, 2023-03-09 at 14:21 -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() {
>>     print("Start")
>>     bb.plain("********************");
>>     bb.plain("*                  *");
>>     bb.plain("*  Hello, World!   *");
>>     bb.plain("*                  *");
>>     bb.plain("********************");
>>     print("Finish")
>> }
>> --
>> will output
>> --
>> ********************
>> *                  *
>> *  Hello, World!   *
>> *                  *
>> ********************
>> Start
>> 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>
>> ---
>>   lib/bb/build.py | 9 +++++++++
>>   1 file changed, 9 insertions(+)
>>
>> diff --git a/lib/bb/build.py b/lib/bb/build.py
>> index 5a172711..eb2d5b59 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,9 +297,17 @@ 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.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:
>> +        if verboseStdoutLogging:
>> +            execio.flush()
>> +            logger.plain("%s" % execio.getvalue())
>> +            sys.stdout = sys.__stdout__
>> +            execio.close()
>>           # 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()
> 
>  From memory, I think exec_func_python can get called recursively so I
> suspect this is going to corrupt sys.stdout. You could save it's value,
> then restore it?
> 

I was actually dithering on this and was saving and restoring it in my 
first iteration. I opted for simplicity when I believed that it was 
allways going to be __stdout__. Regardless if it every changes it would 
be safer to save and restore. I will return to that approach in V2.

> Also, what about stderr?

Tunnel vision at play, I was only focused on stdout :). It should be 
simple to add stderr and I will do so in V2.

MarkA

> 
> Cheers,
> 
> Richard
> 


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

end of thread, other threads:[~2023-03-09 21:54 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-03-09 19:21 [PATCH] build: Make python output print to stdout when running with -v (verbose) Mark Asselstine
2023-03-09 21:49 ` [bitbake-devel] " Richard Purdie
2023-03-09 21:54   ` Mark Asselstine

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).