[bitbake-devel] process: Flush server stdout/stderr before reporting failure

Submitted by Jan Kiszka on Sept. 2, 2018, 8:43 a.m. | Patch ID: 154481

Details

Message ID 192b8cc1-4ea9-1cd7-5a3f-f4c150868a0e@siemens.com
State New
Headers show

Commit Message

Jan Kiszka Sept. 2, 2018, 8:43 a.m.
We need to print exceptions and flush output channels before telling the
client that the server failed. Otherwise the daemon log file may still
be empty when the client opens it for printing.

This fixes error reporting when the output is redirected to a pipe, e.g.
"bitbake target | cat" with a syntax error in a recipes or config file.
That's specifically annoying when bitbake is under the control of a
frontend process such as kas.

Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com>
---
 lib/bb/server/process.py | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

Patch hide | download patch | download mbox

diff --git a/lib/bb/server/process.py b/lib/bb/server/process.py
index 9e5e709f..bcc4eb40 100644
--- a/lib/bb/server/process.py
+++ b/lib/bb/server/process.py
@@ -29,6 +29,7 @@  import array
 import os
 import sys
 import time
+import traceback
 import select
 import socket
 import subprocess
@@ -435,7 +436,11 @@  class BitBakeServer(object):
         try:
             self.cooker = bb.cooker.BBCooker(self.configuration, self.featureset)
             writer.send("ready")
-        except:
+        except (Exception, SystemExit) as e:
+            if type(e) != SystemExit:
+                traceback.print_exc()
+            sys.stdout.flush()
+            sys.stderr.flush()
             writer.send("fail")
             raise
         finally:

Comments

Richard Purdie Sept. 4, 2018, 12:15 p.m.
On Sun, 2018-09-02 at 10:43 +0200, Jan Kiszka wrote:
> We need to print exceptions and flush output channels before telling
> the
> client that the server failed. Otherwise the daemon log file may
> still
> be empty when the client opens it for printing.
> 
> This fixes error reporting when the output is redirected to a pipe,
> e.g.
> "bitbake target | cat" with a syntax error in a recipes or config
> file.
> That's specifically annoying when bitbake is under the control of a
> frontend process such as kas.

Hi,

Could you check if this was already fixed by:

http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=cbe2d3cb0af6c7a5cd368e7dc489960a13648bd0

?

I really want to get these flushes as close to the source of the
problems as we can.

Cheers,

Richard
Richard Purdie Sept. 4, 2018, 12:34 p.m.
On Tue, 2018-09-04 at 13:15 +0100, Richard Purdie wrote:
> On Sun, 2018-09-02 at 10:43 +0200, Jan Kiszka wrote:
> > We need to print exceptions and flush output channels before
> > telling
> > the
> > client that the server failed. Otherwise the daemon log file may
> > still
> > be empty when the client opens it for printing.
> > 
> > This fixes error reporting when the output is redirected to a pipe,
> > e.g.
> > "bitbake target | cat" with a syntax error in a recipes or config
> > file.
> > That's specifically annoying when bitbake is under the control of a
> > frontend process such as kas.
> 
> Hi,
> 
> Could you check if this was already fixed by:
> 
> http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=cbe2d3cb0af6c7a5
> cd368e7dc489960a13648bd0
> 
> ?
> 
> I really want to get these flushes as close to the source of the
> problems as we can.

Looking at the code further, I suspect we should simply be doing:

        writer = ConnectionWriter(self.readypipein)
        self.cooker = bb.cooker.BBCooker(self.configuration, self.featureset)
        writer.send("ready")
        os.close(self.readypipein)
        server.cooker = self.cooker

with no exception handling. The ready pipe would then get closed by the
os._exit() in daemonize which is after the flush. It simplifies the
code as an added bonus...

Cheers,

Richard
Jan Kiszka Sept. 4, 2018, 1:09 p.m.
On 2018-09-04 14:34, Richard Purdie wrote:
> On Tue, 2018-09-04 at 13:15 +0100, Richard Purdie wrote:
>> On Sun, 2018-09-02 at 10:43 +0200, Jan Kiszka wrote:
>>> We need to print exceptions and flush output channels before
>>> telling
>>> the
>>> client that the server failed. Otherwise the daemon log file may
>>> still
>>> be empty when the client opens it for printing.
>>>
>>> This fixes error reporting when the output is redirected to a pipe,
>>> e.g.
>>> "bitbake target | cat" with a syntax error in a recipes or config
>>> file.
>>> That's specifically annoying when bitbake is under the control of a
>>> frontend process such as kas.
>>
>> Hi,
>>
>> Could you check if this was already fixed by:
>>
>> http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=cbe2d3cb0af6c7a5
>> cd368e7dc489960a13648bd0

Looks similar on first glance, but it only partly helps with exceptions. 
We get from

$ bitbake | cat
ERROR: Unable to start bitbake server

to

$ bitbake | cat
ERROR: Unable to start bitbake server
ERROR: Server log for this session (/work/build/bitbake-cookerdaemon.log):
--- Starting bitbake server pid 149 at 2018-09-04 13:02:15.144583 ---

while it should have

$ bitbake
ERROR: Unable to start bitbake server
ERROR: Last 10 lines of server log for this session 
(/work/build/bitbake-cookerdaemon.log):
Traceback (most recent call last):
   File "/work/isar/bitbake/lib/bb/daemonize.py", line 77, in createDaemon
     function()
   File "/work/isar/bitbake/lib/bb/server/process.py", line 433, in 
_startServer
     self.cooker = bb.cooker.BBCooker(self.configuration, self.featureset)
   File "/work/isar/bitbake/lib/bb/cooker.py", line 178, in __init__
     self.configwatcher = pyinotify.WatchManager()
   File "/work/isar/bitbake/lib/pyinotify.py", line 1764, in __init__
     raise OSError(err % self._inotify_wrapper.str_errno())
OSError: Cannot initialize new instance of inotify, Errno=Too many open 
files (EMFILE)

>>
>> ?
>>
>> I really want to get these flushes as close to the source of the
>> problems as we can.
> 
> Looking at the code further, I suspect we should simply be doing:
> 
>          writer = ConnectionWriter(self.readypipein)
>          self.cooker = bb.cooker.BBCooker(self.configuration, self.featureset)
>          writer.send("ready")
>          os.close(self.readypipein)
>          server.cooker = self.cooker
> 
> with no exception handling. The ready pipe would then get closed by the
> os._exit() in daemonize which is after the flush. It simplifies the
> code as an added bonus...

Tried that, but it does not work that way, it just hangs.

As I wrote, the test case is trivial: just direct the output of bitbake 
into a pipe (bitbake | cat).

Jan
Richard Purdie Sept. 5, 2018, 12:14 a.m.
On Tue, 2018-09-04 at 15:09 +0200, Jan Kiszka wrote:
> Looks similar on first glance, but it only partly helps with
> exceptions. 
> We get from
> 
> $ bitbake | cat
> ERROR: Unable to start bitbake server
> 
> to
> 
> $ bitbake | cat
> ERROR: Unable to start bitbake server
> ERROR: Server log for this session (/work/build/bitbake-
> cookerdaemon.log):
> --- Starting bitbake server pid 149 at 2018-09-04 13:02:15.144583 ---
> 
> while it should have
> 
> $ bitbake
> ERROR: Unable to start bitbake server
> ERROR: Last 10 lines of server log for this session 
> (/work/build/bitbake-cookerdaemon.log):
> Traceback (most recent call last):
>    File "/work/isar/bitbake/lib/bb/daemonize.py", line 77, in
> createDaemon
>      function()
>    File "/work/isar/bitbake/lib/bb/server/process.py", line 433, in 
> _startServer
>      self.cooker = bb.cooker.BBCooker(self.configuration,
> self.featureset)
>    File "/work/isar/bitbake/lib/bb/cooker.py", line 178, in __init__
>      self.configwatcher = pyinotify.WatchManager()
>    File "/work/isar/bitbake/lib/pyinotify.py", line 1764, in __init__
>      raise OSError(err % self._inotify_wrapper.str_errno())
> OSError: Cannot initialize new instance of inotify, Errno=Too many
> open 
> files (EMFILE)

The more I looked into this the more problems I found. I've put this in
for some testing which should address the issues:

http://git.yoctoproject.org/cgit.cgi/poky/commit/?h=master-next&id=dae574dd680f4f9db0b1447266742fa127963842

Cheers,

Richard
Jan Kiszka Sept. 7, 2018, 9:48 a.m.
On 2018-09-05 02:14, richard.purdie@linuxfoundation.org wrote:
> On Tue, 2018-09-04 at 15:09 +0200, Jan Kiszka wrote:
>> Looks similar on first glance, but it only partly helps with
>> exceptions.
>> We get from
>>
>> $ bitbake | cat
>> ERROR: Unable to start bitbake server
>>
>> to
>>
>> $ bitbake | cat
>> ERROR: Unable to start bitbake server
>> ERROR: Server log for this session (/work/build/bitbake-
>> cookerdaemon.log):
>> --- Starting bitbake server pid 149 at 2018-09-04 13:02:15.144583 ---
>>
>> while it should have
>>
>> $ bitbake
>> ERROR: Unable to start bitbake server
>> ERROR: Last 10 lines of server log for this session
>> (/work/build/bitbake-cookerdaemon.log):
>> Traceback (most recent call last):
>>     File "/work/isar/bitbake/lib/bb/daemonize.py", line 77, in
>> createDaemon
>>       function()
>>     File "/work/isar/bitbake/lib/bb/server/process.py", line 433, in
>> _startServer
>>       self.cooker = bb.cooker.BBCooker(self.configuration,
>> self.featureset)
>>     File "/work/isar/bitbake/lib/bb/cooker.py", line 178, in __init__
>>       self.configwatcher = pyinotify.WatchManager()
>>     File "/work/isar/bitbake/lib/pyinotify.py", line 1764, in __init__
>>       raise OSError(err % self._inotify_wrapper.str_errno())
>> OSError: Cannot initialize new instance of inotify, Errno=Too many
>> open
>> files (EMFILE)
> 
> The more I looked into this the more problems I found. I've put this in
> for some testing which should address the issues:
> 
> http://git.yoctoproject.org/cgit.cgi/poky/commit/?h=master-next&id=dae574dd680f4f9db0b1447266742fa127963842
> 

Yep, it does here as well!

Thanks,
Jan