[bitbake-devel] daemonize: Flush stdio on exit

Submitted by Joshua Watt on Aug. 21, 2018, 2:04 p.m. | Patch ID: 153962

Details

Message ID 20180821140416.10764-1-JPEWhacker@gmail.com
State New
Headers show

Commit Message

Joshua Watt Aug. 21, 2018, 2:04 p.m.
In spite of a comment suggesting otherwise, os._exit() does not flush
buffered output from file descriptors before exiting the process like
os.exit() does. This means that any un-flushed output is lost in the
daemon process, in particular the traceback from any thrown exceptions,
making debugging exceptions in the daemon quite difficult.

The solution is to flush stdout and stderr before exiting.

Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
---
 bitbake/lib/bb/daemonize.py | 9 +++++++--
 1 file changed, 7 insertions(+), 2 deletions(-)

Patch hide | download patch | download mbox

diff --git a/bitbake/lib/bb/daemonize.py b/bitbake/lib/bb/daemonize.py
index 8300d1d0f0f..bf16793468e 100644
--- a/bitbake/lib/bb/daemonize.py
+++ b/bitbake/lib/bb/daemonize.py
@@ -49,8 +49,8 @@  def createDaemon(function, logfile):
             # exit() or _exit()?
             # _exit is like exit(), but it doesn't call any functions registered
             # with atexit (and on_exit) or any registered signal handlers.  It also
-            # closes any open file descriptors.  Using exit() may cause all stdio
-            # streams to be flushed twice and any temporary files may be unexpectedly
+            # closes any open file descriptors, but doesn't flush any buffered output.
+            # Using exit() may cause all any temporary files to be unexpectedly
             # removed.  It's therefore recommended that child branches of a fork()
             # and the parent branch(es) of a daemon use _exit().
             os._exit(0)
@@ -79,4 +79,9 @@  def createDaemon(function, logfile):
         traceback.print_exc()
     finally:
         bb.event.print_ui_queue()
+        # os._exit() doesn't flush open files like os.exit() does. Manually flush
+        # stdout and stderr so that any logging output will be seen, particularly
+        # exception tracebacks.
+        sys.stdout.flush()
+        sys.stderr.flush()
         os._exit(0)

Comments

Rasmus Villemoes Aug. 22, 2018, 1:33 p.m.
On 2018-08-21 16:04, Joshua Watt wrote:
> In spite of a comment suggesting otherwise, os._exit() does not flush
> buffered output from file descriptors before exiting the process like
> os.exit() does. This means that any un-flushed output is lost in the
> daemon process, in particular the traceback from any thrown exceptions,
> making debugging exceptions in the daemon quite difficult.
> 
> The solution is to flush stdout and stderr before exiting.
> 
> Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
> ---
>  bitbake/lib/bb/daemonize.py | 9 +++++++--
>  1 file changed, 7 insertions(+), 2 deletions(-)
> 
> diff --git a/bitbake/lib/bb/daemonize.py b/bitbake/lib/bb/daemonize.py
> index 8300d1d0f0f..bf16793468e 100644
> --- a/bitbake/lib/bb/daemonize.py
> +++ b/bitbake/lib/bb/daemonize.py
> @@ -49,8 +49,8 @@ def createDaemon(function, logfile):
>              # exit() or _exit()?
>              # _exit is like exit(), but it doesn't call any functions registered
>              # with atexit (and on_exit) or any registered signal handlers.  It also
> -            # closes any open file descriptors.  Using exit() may cause all stdio
> -            # streams to be flushed twice and any temporary files may be unexpectedly
> +            # closes any open file descriptors, but doesn't flush any buffered output.
> +            # Using exit() may cause all any temporary files to be unexpectedly
>              # removed.  It's therefore recommended that child branches of a fork()
>              # and the parent branch(es) of a daemon use _exit().
>              os._exit(0)
> @@ -79,4 +79,9 @@ def createDaemon(function, logfile):
>          traceback.print_exc()
>      finally:
>          bb.event.print_ui_queue()
> +        # os._exit() doesn't flush open files like os.exit() does. Manually flush
> +        # stdout and stderr so that any logging output will be seen, particularly
> +        # exception tracebacks.
> +        sys.stdout.flush()
> +        sys.stderr.flush()
>          os._exit(0)
> 

Well, that's of course better than not getting the output, but there's
then the issue of double printing: The intermediate child does _exit(),
but the grandparent may have had stuff in the stdio buffers before the
very first fork(), and that content would be inherited down to the
grandchild. So I think you should (also) explicitly flush stdout and
stderr before the first fork().
Richard Purdie Aug. 24, 2018, 6:57 a.m.
On Wed, 2018-08-22 at 15:33 +0200, Rasmus Villemoes wrote:
> On 2018-08-21 16:04, Joshua Watt wrote:
> > In spite of a comment suggesting otherwise, os._exit() does not
> > flush
> > buffered output from file descriptors before exiting the process
> > like
> > os.exit() does. This means that any un-flushed output is lost in
> > the
> > daemon process, in particular the traceback from any thrown
> > exceptions,
> > making debugging exceptions in the daemon quite difficult.
> > 
> > The solution is to flush stdout and stderr before exiting.
> > 
> > Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
> > ---
> >  bitbake/lib/bb/daemonize.py | 9 +++++++--
> >  1 file changed, 7 insertions(+), 2 deletions(-)
> > 
> > diff --git a/bitbake/lib/bb/daemonize.py
> > b/bitbake/lib/bb/daemonize.py
> > index 8300d1d0f0f..bf16793468e 100644
> > --- a/bitbake/lib/bb/daemonize.py
> > +++ b/bitbake/lib/bb/daemonize.py
> > @@ -49,8 +49,8 @@ def createDaemon(function, logfile):
> >              # exit() or _exit()?
> >              # _exit is like exit(), but it doesn't call any
> > functions registered
> >              # with atexit (and on_exit) or any registered signal
> > handlers.  It also
> > -            # closes any open file descriptors.  Using exit() may
> > cause all stdio
> > -            # streams to be flushed twice and any temporary files
> > may be unexpectedly
> > +            # closes any open file descriptors, but doesn't flush
> > any buffered output.
> > +            # Using exit() may cause all any temporary files to be
> > unexpectedly
> >              # removed.  It's therefore recommended that child
> > branches of a fork()
> >              # and the parent branch(es) of a daemon use _exit().
> >              os._exit(0)
> > @@ -79,4 +79,9 @@ def createDaemon(function, logfile):
> >          traceback.print_exc()
> >      finally:
> >          bb.event.print_ui_queue()
> > +        # os._exit() doesn't flush open files like os.exit() does.
> > Manually flush
> > +        # stdout and stderr so that any logging output will be
> > seen, particularly
> > +        # exception tracebacks.
> > +        sys.stdout.flush()
> > +        sys.stderr.flush()
> >          os._exit(0)
> > 
> 
> Well, that's of course better than not getting the output, but
> there's then the issue of double printing: The intermediate child
> does _exit(), but the grandparent may have had stuff in the stdio
> buffers before the very first fork(), and that content would be
> inherited down to the grandchild. So I think you should (also)
> explicitly flush stdout and stderr before the first fork().

You're correct, we should do that. I was thinking we did flush things
before forking but looking at the code I'm thinking of the fork() call
in bitbake-worker, not the one in daemonize.py.

I'd happily take a patch if someone wants to work one up!

Cheers,

Richard
Richard Purdie Sept. 5, 2018, 5:03 p.m.
On Fri, 2018-08-24 at 07:57 +0100, Richard Purdie wrote:
> On Wed, 2018-08-22 at 15:33 +0200, Rasmus Villemoes wrote:
> > Well, that's of course better than not getting the output, but
> > there's then the issue of double printing: The intermediate child
> > does _exit(), but the grandparent may have had stuff in the stdio
> > buffers before the very first fork(), and that content would be
> > inherited down to the grandchild. So I think you should (also)
> > explicitly flush stdout and stderr before the first fork().
> 
> You're correct, we should do that. I was thinking we did flush things
> before forking but looking at the code I'm thinking of the fork()
> call
> in bitbake-worker, not the one in daemonize.py.
> 
> I'd happily take a patch if someone wants to work one up!

I fixed this whilst looking at the other logging/buffer issues.

Cheers,

Richard