Repository: cython/cython
Pull request: Capturing and redirecting stdout/stderr for %%cython-magic
Fixes #3751 as discussed [here](https://github.com/cython/cython/issues/3751#issuecomment-702725848)

Some compilers (MSVC) and linkers write errors to stdout (and not stderr), so we need to catch both and if an error caught, redirect both to sys.stderr.

After fix, for this code:

```
%%cython
cdef extern from *:
    """
    xxxx a;
    """
    int a;
def doit():
    return a
```
Shows error:
```
.../_cython_magic_0c7dc5ea1c624caa7d5b6b78d977eedea31eb934.c:622:5: error: unknown type name ‘xxxx’
     xxxx a;
```
on Linux and
```
_cython_magic_18af9232b2d51cf1c8df01fd5af261c66fd7b162.c
...\_cython_magic_18af9232b2d51cf1c8df01fd5af261c66fd7b162.c(610): error C2061: syntax error: identifier 'a'
...\_cython_magic_18af9232b2d51cf1c8df01fd5af261c66fd7b162.c(610): error C2059: syntax error: ';'
...\_cython_magic_18af9232b2d51cf1c8df01fd5af261c66fd7b162.c(1073): error C2065: 'a': undeclared identifier
```
on Windows (seen in IPython-notebook).

Problem statement:
[Jupyter] Fails silently on importing C header file in same folder
The code below "evaluates" without any error messages. By myadd is never defined, and the annotation output is never produced.

Removing the dependency on add.h makes everything work without a problem.

## File system:
```
src/
    - add.h
    - Notebook.ipynb
```
## C Header File (standalone)
```c
// add.h
int add(int x, int y) {
    return x + y;
}
```
## Jupyter Notebook:
```py
# Input cell [1]
%load_ext cython
```

```py
# Input cell [2]
%%cython --annotate

cdef extern from "add.h":
    int add(int x, int y)

cpdef myadd(int x, int y):
    cdef int total = add(x, y)
    return total
```

---

To reproduce/use the same environment, you can use docker:
```sh
docker run --rm -it -p8888:8888 jupyter/scipy-notebook:ea01ec4d9f57
```

Hints from issue discussion:
Changing to the following makes it work. (Notice that I added `-I.` at the top)
```py
# Input cell [2]
%%cython --annotate -I.

cdef extern from "add.h":
    int add(int x, int y)

cpdef myadd(int x, int y):
    cdef int total = add(x, y)
    return total
```

Would be nice if an error was thrown, saying the header file was not found. Failing silently makes it a lot harder to track down the problem.
The compile output from Jupyter output appears in the terminal that Jupyter is run in, not the notebook itself.

It would be nice if it could be redirected to the notebook (at least on failure) - it'd save a lot of confusion for people. I don't think capturing and redirecting it is particularly easy though.
Duplicate of https://github.com/cython/cython/issues/1569

~~Try with the --verbose option and it should be more obvious~~
On closer inspection the verbose option doesn't look to be that much more verbose. I think intercepting the compiler output is harder than it looks. I'll reopen and someone else can decide what to do with this.
I think the problem comes with  #3196: While in IPython one can see things printed to c-level stdout this is not the case for Jupiter-notebooks.

There is `wurlitzer` (https://github.com/minrk/wurlitzer) which has the IPython-magic `%load_ext wurlizer` to capture C-level stdout for Jupiter-notebooks, sadly it works only for Linux (and probably macOS), but this is probably not the way to go.

Another problem with #3196 is that while it catches `distutils.errors.CompileError` it doesn't catch the `distutils.errors.LinkError`, for which one still sees the old message.

Maybe a better solution would be to catch both exceptions, but also to print to `sys.stderr` (which for Jupiter-notebook has nothing to do with C-level stderr) that an error has happened while compiling/linking and the user should see logs on C-level stderr/stdout?
Isn't it enough to divert `sys.stderr` before running the extension build?
That obviously introduces concurrency problems if we're not the only thread creating output at this time, but that case should be fairly rare, at least for most users.

Everything beyond that, I'd say, should be improved on the side of [setuptools](https://github.com/pypa/setuptools/tree/master/setuptools/_distutils), which controls the C compiler run.
@scoder 
> Isn't it enough to divert `sys.stderr` before running the extension build?

Not sure I understand that, I think redirecting `sys.stderr` will not change where the C-level output will be written to?

When compiler (or linker) is called by `distutils`, the output  of the compiler/linker isn't captured (see [here](https://github.com/python/cpython/blob/497126f7ea955ee005e78f2cdd61f175d4fcdbb2/Lib/distutils/spawn.py#L74-L77)):

```
    try:
        proc = subprocess.Popen(cmd, env=env)
        proc.wait()
        exitcode = proc.returncode
```

and goes directly to the C-level stdout/stderr bypassing the whole python-IO-machinery.  In normal python/ipython session we still see linker/gcc-output, because it is the same terminal. However in a jupyter-notebook, only things printed to python's stdout/stderr are rendered in the browser, not the things printed directly to C-level stdout/stderr (which are seen in the terminal from which the jupyter was started).

This is the reason why right now, even if compile step failed, a Jupyter user assumes, that everything worked as expected and sees no feedback, that the building the extension failed, see #3840 

1)  The best way is probably to catch stderr/stdout while calling compiler/linker in distutils and redirect this to python's stderr/stdout (not sure why this wasn't done in the first place). Not sure whether this solution makes sense or is feasible any time soon.

2) First workaround: One could catch the C-level output while executing %%cython, and redirect it to sys.stderr. There is [wurlitzer](https://github.com/minrk/wurlitzer), which does that (based on this [article](https://eli.thegreenplace.net/2015/redirecting-all-kinds-of-stdout-in-python/)), but its approach with `ctypes` doesn't work on Windows (at least not out-of-the box, I also wasn't able to make it work, but maybe it is just me).  However, it is possible to write a C-extension, which would work for Linux and Windows. I have written a prototype with Cython some time ago (https://github.com/realead/coutcatcher), not sure it is waterproof tough.

3) Minimal workaround (at core of PR  #3819):  notify the user, that the build didn't succeed, which gives a hint to look for the output in terminal.

Even if I bug python-devs with 1) now, it will take time (if it will be considered a valid concern) to be fixed/improved. Until then 3) would be not ideal, but at least an improvement compared to the current situation.

What would be a good solution from your point of view? I'll try my best to implement it and to provide a PR to solve this problem.


In our test runner, we do this: https://github.com/cython/cython/blob/af757997c7d13c00b579fd00393350d9367dd12a/Cython/Utils.py#L396-L433
Admittedly, that's a bit involved, but it gets the job done.

Note that the people to approach for 1) are not the CPython devs but the setuptools devs. The distutils package in the standard library has been deprecated and development has moved to setuptools. See my link above.

Commit message: call explicit close on TextIOWrapper

Patch to review:
diff --git a/Cython/Build/IpythonMagic.py b/Cython/Build/IpythonMagic.py
index 7aa7bf666b7..3bf0b7c325a 100644
--- a/Cython/Build/IpythonMagic.py
+++ b/Cython/Build/IpythonMagic.py
@@ -55,6 +55,7 @@
 import copy
 import distutils.log
 import textwrap
+from collections import OrderedDict
 
 IO_ENCODING = sys.getfilesystemencoding()
 IS_PY2 = sys.version_info[0] < 3
@@ -82,6 +83,7 @@
 from ..Compiler.Errors import CompileError
 from .Inline import cython_inline
 from .Dependencies import cythonize
+from ..Utils import captured_fd
 
 
 PGO_CONFIG = {
@@ -106,6 +108,43 @@ def encode_fs(name):
         return name
 
 
+def get_encoding_candidates():
+    candidates = [sys.getdefaultencoding()]
+    try:
+        candidates.extend([sys.stdout.encoding, sys.stdin.encoding])
+    except AttributeError:
+        pass
+    try:
+        candidates.extend([sys.__stdout__.encoding, sys.__stdin__.encoding])
+    except AttributeError:
+        pass
+    unique_candidates = OrderedDict.fromkeys(candidates)
+    # encoding might be None (i.e. somebody redirects stdout):
+    unique_candidates.pop(None, None)
+    return list(unique_candidates)
+
+
+def prepare_captured(captured):
+    captured_bytes = captured and captured().strip()
+    if not captured_bytes:
+        return None
+    for encoding in get_encoding_candidates():
+        try:
+            return captured_bytes.decode(encoding)
+        except UnicodeDecodeError:
+            pass
+    # last resort: print at least the readable ascii parts correctly.
+    return captured_bytes.decode('latin-1')
+
+
+def print_captured(captured, output, header_line):
+    captured = prepare_captured(captured)
+    if captured:
+        if header_line:
+            output.write(header_line)
+        output.write(captured)
+
+
 @magics_class
 class CythonMagics(Magics):
 
@@ -342,13 +381,25 @@ def critical_function(data):
             if args.pgo:
                 self._profile_pgo_wrapper(extension, lib_dir)
 
+        def print_compiler_output(stdout, stderr, where):
+            # On windows, errors are printed to stdout, we redirect both to sys.stderr.
+            print_captured(stdout, where, u"Content of stdout:\n")
+            print_captured(stderr, where, u"Content of stderr:\n")
+
+        get_stderr = get_stdout = None
         try:
-            self._build_extension(extension, lib_dir, pgo_step_name='use' if args.pgo else None,
-                                  quiet=args.quiet)
-        except distutils.errors.CompileError:
-            # Build failed and printed error message
+            with captured_fd(1) as get_stdout:
+                with captured_fd(2) as get_stderr:
+                    self._build_extension(
+                        extension, lib_dir, pgo_step_name='use' if args.pgo else None, quiet=args.quiet)
+        except (distutils.errors.CompileError, distutils.errors.LinkError):
+            # Build failed, print error message from compiler/linker
+            print_compiler_output(get_stdout, get_stderr, sys.stderr)
             return None
 
+        # Build seems ok, but we might still want to show any warnings that occurred
+        print_compiler_output(get_stdout, get_stderr, sys.stdout)
+
         module = imp.load_dynamic(module_name, module_path)
         self._import_all(module)
 
diff --git a/Cython/Build/Tests/TestIpythonMagic.py b/Cython/Build/Tests/TestIpythonMagic.py
index ed4db98cbba..febb480ac8f 100644
--- a/Cython/Build/Tests/TestIpythonMagic.py
+++ b/Cython/Build/Tests/TestIpythonMagic.py
@@ -6,6 +6,7 @@
 from __future__ import absolute_import
 
 import os
+import io
 import sys
 from contextlib import contextmanager
 from Cython.Build import IpythonMagic
@@ -29,6 +30,26 @@ def skip_if_not_installed(c):
 except ImportError:
     pass
 
+
+@contextmanager
+def capture_output():
+    backup = sys.stdout, sys.stderr
+    try:
+        replacement = [
+             io.TextIOWrapper(io.BytesIO(), encoding=sys.stdout.encoding),
+             io.TextIOWrapper(io.BytesIO(), encoding=sys.stderr.encoding),
+        ]
+        sys.stdout, sys.stderr = replacement
+        output = []
+        yield output
+    finally:
+        sys.stdout, sys.stderr = backup
+        for wrapper in replacement:
+            wrapper.seek(0)  # rewind
+            output.append(wrapper.read())
+            wrapper.close()
+
+
 code = u"""\
 def f(x):
     return 2*x
@@ -48,6 +69,27 @@ def main():
 main()
 """
 
+compile_error_code = u'''\
+cdef extern from *:
+    """
+    xxx a=1;
+    """
+    int a;
+def doit():
+    return a
+'''
+
+compile_warning_code = u'''\
+cdef extern from *:
+    """
+    #pragma message ( "CWarning" )
+    int a = 42;
+    """
+    int a;
+def doit():
+    return a
+'''
+
 
 if sys.platform == 'win32':
     # not using IPython's decorators here because they depend on "nose"
@@ -143,6 +185,39 @@ def test_cython2(self):
         self.assertEqual(ip.user_ns['g'], 2 // 10)
         self.assertEqual(ip.user_ns['h'], 2 // 10)
 
+    def test_cython_compile_error_shown(self):
+        ip = self._ip
+        with capture_output() as out:
+            ip.run_cell_magic('cython', '-3', compile_error_code)
+        captured_out, captured_err = out
+
+        # it could be that c-level output is captured by distutil-extension
+        # (and not by us) and is printed to stdout:
+        captured_all = captured_out + "\n" + captured_err
+        self.assertTrue("error" in captured_all, msg="error in " + captured_all)
+
+    def test_cython_link_error_shown(self):
+        ip = self._ip
+        with capture_output() as out:
+            ip.run_cell_magic('cython', '-3 -l=xxxxxxxx', code)
+        captured_out, captured_err = out
+
+        # it could be that c-level output is captured by distutil-extension
+        # (and not by us) and is printed to stdout:
+        captured_all = captured_out + "\n!" + captured_err
+        self.assertTrue("error" in captured_all, msg="error in " + captured_all)
+
+    def test_cython_warning_shown(self):
+        ip = self._ip
+        with capture_output() as out:
+            # force rebuild, otherwise no warning as after the first success
+            # no build step is performed
+            ip.run_cell_magic('cython', '-3 -f', compile_warning_code)
+        captured_out, captured_err = out
+
+        # check that warning was printed to stdout even if build hasn't failed
+        self.assertTrue("CWarning" in captured_out)
+
     @skip_win32('Skip on Windows')
     def test_cython3_pgo(self):
         # The Cython cell defines the functions f() and call().


Code review comments:
diff_hunk: @@ -342,13 +381,25 @@ def critical_function(data):
             if args.pgo:
                 self._profile_pgo_wrapper(extension, lib_dir)
 
+        def print_compiler_output(stdout, stderr, where):
+            # On windows, errors are printed to stdout, we redirect both to sys.stderr.
+            print_captured(stdout, where, u"Content of stdout:\n")
+            print_captured(stderr, where, u"Content of stderr:\n")
+
+        get_stderr = get_stdout = None
         try:
-            self._build_extension(extension, lib_dir, pgo_step_name='use' if args.pgo else None,
-                                  quiet=args.quiet)
-        except distutils.errors.CompileError:
-            # Build failed and printed error message
+            with captured_fd(1) as get_stdout:
+                with captured_fd(2) as get_stderr:
+                    self._build_extension(
+                        extension, lib_dir, pgo_step_name='use' if args.pgo else None, quiet=args.quiet)
+        except (distutils.errors.CompileError, distutils.errors.LinkError):
+            # Build failed, print error message from compiler/linker
+            print_compiler_output(get_stdout, get_stderr, sys.stderr)
             return None
 
+        # Build seems ok, but we might still want to show any warnings that occurred
+        print_compiler_output(get_stdout, get_stderr, sys.stdout)
path: Cython/Build/IpythonMagic.py
text: @user1:
```suggestion
        print_compiler_output(get_stdout(), get_stderr(), sys.stdout)
```

diff_hunk: @@ -342,13 +381,25 @@ def critical_function(data):
             if args.pgo:
                 self._profile_pgo_wrapper(extension, lib_dir)
 
+        def print_compiler_output(stdout, stderr, where):
+            # On windows, errors are printed to stdout, we redirect both to sys.stderr.
+            print_captured(stdout, where, u"Content of stdout:\n")
+            print_captured(stderr, where, u"Content of stderr:\n")
+
+        get_stderr = get_stdout = None
         try:
-            self._build_extension(extension, lib_dir, pgo_step_name='use' if args.pgo else None,
-                                  quiet=args.quiet)
-        except distutils.errors.CompileError:
-            # Build failed and printed error message
+            with captured_fd(1) as get_stdout:
+                with captured_fd(2) as get_stderr:
+                    self._build_extension(
+                        extension, lib_dir, pgo_step_name='use' if args.pgo else None, quiet=args.quiet)
+        except (distutils.errors.CompileError, distutils.errors.LinkError):
+            # Build failed, print error message from compiler/linker
+            print_compiler_output(get_stdout, get_stderr, sys.stderr)
path: Cython/Build/IpythonMagic.py
text: @user1:
```suggestion
            print_compiler_output(get_stdout(), get_stderr(), sys.stderr)
```

diff_hunk: @@ -106,6 +108,43 @@ def encode_fs(name):
         return name
 
 
+def get_encoding_candidates():
+    candidates = [sys.getdefaultencoding()]
+    try:
+        candidates.extend([sys.stdout.encoding, sys.stdin.encoding])
+    except AttributeError:
+        pass
+    try:
+        candidates.extend([sys.__stdout__.encoding, sys.__stdin__.encoding])
+    except AttributeError:
+        pass
+    unique_candidates = OrderedDict.fromkeys(candidates)
+    # encoding might be None (i.e. somebody redirects stdout):
+    unique_candidates.pop(None, None)
+    return list(unique_candidates)
+
+
+def prepare_captured(captured):
+    captured_bytes = captured and captured().strip()
+    if not captured_bytes:
+        return None
+    for encoding in get_encoding_candidates():
+        try:
+            return captured_bytes.decode(encoding)
+        except UnicodeDecodeError:
+            pass
+    # last resort: print at least the readable ascii parts correctly.
+    return captured_bytes.decode('latin-1')
+
+
+def print_captured(captured, output, header_line):
path: Cython/Build/IpythonMagic.py
text: @user1:
If it's optional, make it optional.
```suggestion
def print_captured(captured, output, header_line=None):
```

@author:
Done: https://github.com/cython/cython/pull/3872/commits/d9c07d6f315ac1c054381a1637907c97d660ccd5

diff_hunk: @@ -106,6 +108,43 @@ def encode_fs(name):
         return name
 
 
+def get_encoding_candidates():
+    candidates = [sys.getdefaultencoding()]
+    try:
+        candidates.extend([sys.stdout.encoding, sys.stdin.encoding])
+    except AttributeError:
+        pass
+    try:
+        candidates.extend([sys.__stdout__.encoding, sys.__stdin__.encoding])
+    except AttributeError:
+        pass
+    unique_candidates = OrderedDict.fromkeys(candidates)
+    # encoding might be None (i.e. somebody redirects stdout):
+    unique_candidates.pop(None, None)
+    return list(unique_candidates)
+
+
+def prepare_captured(captured):
+    captured_bytes = captured and captured().strip()
path: Cython/Build/IpythonMagic.py
text: @user1:
`captured` can be None in the `finally` clause in `runtests.py`, but not here.
```suggestion
    captured_bytes = captured.strip()
```

@author:
simplified: https://github.com/cython/cython/pull/3872/commits/3efc7b11c9efd5e435146bd766f0b74d230bcb06

diff_hunk: @@ -106,6 +108,43 @@ def encode_fs(name):
         return name
 
 
+def get_encoding_candidates():
+    candidates = [sys.getdefaultencoding()]
+    try:
+        candidates.extend([sys.stdout.encoding, sys.stdin.encoding])
+    except AttributeError:
+        pass
+    try:
+        candidates.extend([sys.__stdout__.encoding, sys.__stdin__.encoding])
+    except AttributeError:
+        pass
+    unique_candidates = OrderedDict.fromkeys(candidates)
+    # encoding might be None (i.e. somebody redirects stdout):
+    unique_candidates.pop(None, None)
+    return list(unique_candidates)
path: Cython/Build/IpythonMagic.py
text: @user1:
What about this (I'm not sure about the order of the streams yet):
```suggestion
    for stream in (sys,stdout, sys.stdin, sys.__stdout__, sys.__stdin__):
        encoding = getattr(stream, 'encoding', None)
        if encoding is not None and encoding not in candidates:
            candidates.append(encoding)
    return candidates
```
There's probably only going to be one, or sometimes two or three, different encodings here. No need to go for something algorithmically complex.

@author:
D'accord, https://github.com/cython/cython/pull/3872/commits/8e071b06a2aa5811a43bedc22d298f0ed1f8e5ac