Fix suppress_output_file bug where event_callback was not called (#943)

Fix suppress_output_file bug where event_callback was not called

Sorry, I had a major flaw with #937 and I should have tested that better before it was merged.
The handle was not passed to pexpect, and that was wrong. The handle is the way that it dispatches events to the event_callback. Even if you do not intend to write to the stdout file, this is necessary.
Design-wise, if suppress_output_file is given, we do want to use the stdout handle wrapper, but we do not want to use the stdout handle itself. I think this code structure articulates that about as best as possible. Alternatively, we could create a null handler and pass that to OutputEventFilter, instead of handling the None case.

Separately, I may have discovered a bug related to the test failures on the prior PR.

  
    
      ansible-runner/ansible_runner/utils/__init__.py
    
    
         Line 373
      in
      d013044
    
    
    
    

        
          
           event_data['stdout'] = stdout_chunk[:-2] if len(stdout_chunk) > 2 else "" 
        
    
  


This is assuming the .splitlines(True) leaves \r\n at the end of the line. This is... not universal. Because of that, the final character in the echo command gets truncated, because it has a \n without the \r. This looks completely fixable, but I wish to keep that separate.

Reviewed-by: David Shrewsbury <None>
Reviewed-by: None <None>
Reviewed-by: Alexander Sowitzki <dev@eqrx.net>

ansible_runner/runner.py

@@ -10,7 +10,6 @@
 import collections
 import datetime
 import logging
-from io import StringIO
 
 import six
 import pexpect
@@ -156,8 +155,8 @@ def run(self):
             stdout_handle = codecs.open(stdout_filename, 'w', encoding='utf-8')
             stderr_handle = codecs.open(stderr_filename, 'w', encoding='utf-8')
         else:
-            stdout_handle = StringIO()
-            stderr_handle = StringIO()
+            stdout_handle = None
+            stderr_handle = None
 
         stdout_handle = OutputEventFilter(stdout_handle, self.event_callback, suppress_ansible_output, output_json=self.config.json_mode)
         stderr_handle = OutputEventFilter(stderr_handle, self.event_callback, suppress_ansible_output, output_json=self.config.json_mode)
@@ -313,8 +312,7 @@ def run(self):
                     echo=False,
                     use_poll=self.config.pexpect_use_poll,
                 )
-                if not self.config.suppress_output_file:
-                    child.logfile_read = stdout_handle
+                child.logfile_read = stdout_handle
             except pexpect.exceptions.ExceptionPexpect as e:
                 child = collections.namedtuple(
                     'MissingProcess', 'exitstatus isalive close'

ansible_runner/utils/__init__.py

@@ -279,7 +279,8 @@ def __init__(self, handle, event_callback,
         self.suppress_ansible_output = suppress_ansible_output
 
     def flush(self):
-        self._handle.flush()
+        if self._handle:
+            self._handle.flush()
 
     def write(self, data):
         self._buffer.write(data)
@@ -318,8 +319,9 @@ def write(self, data):
                     )
                     sys.stdout.write("\n")
                     sys.stdout.flush()
-                self._handle.write(stdout_actual + "\n")
-                self._handle.flush()
+                if self._handle:
+                    self._handle.write(stdout_actual + "\n")
+                    self._handle.flush()
 
             self._last_chunk = remainder
         else:
@@ -338,8 +340,9 @@ def write(self, data):
                         sys.stdout.write(
                             line.encode('utf-8') if PY2 else line
                         )
-                    self._handle.write(line)
-                    self._handle.flush()
+                    if self._handle:
+                        self._handle.write(line)
+                        self._handle.flush()
                 self._buffer = StringIO()
                 # put final partial line back on buffer
                 if remainder:
@@ -351,7 +354,8 @@ def close(self):
             self._emit_event(value)
             self._buffer = StringIO()
         self._event_callback(dict(event='EOF'))
-        self._handle.close()
+        if self._handle:
+            self._handle.close()
 
     def _emit_event(self, buffered_stdout, next_event_data=None):
         next_event_data = next_event_data or {}

test/unit/test_runner.py

@@ -151,24 +151,31 @@ def test_status_callback_interface(rc, mocker):
 def test_stdout_file_write(rc, runner_mode):
     if runner_mode == 'pexpect':
         pytest.skip('Writing to stdout can be flaky, probably due to some pexpect bug')
-    rc.command = ['echo', 'hello_world_marker']
+    rc.command = ['echo', 'hello_world_marker ']  # workaround bug in stdout handl wrapper
     rc.runner_mode = runner_mode
-    status, exitcode = Runner(config=rc).run()
+    runner = Runner(config=rc)
+    status, exitcode = runner.run()
     assert status == 'successful'
     stdout_path = Path(rc.artifact_dir) / 'stdout'
-    # this can be subject to a race condition so we will be patient with the check
+    # poll until we are sure the file has been written to
     for _ in iterate_timeout(30.0, 'stdout file to be written', interval=0.2):
-        if 'hello_world_marker' in stdout_path.read_text():
+        if stdout_path.read_text().strip():
             break
+    assert 'hello_world_marker' in stdout_path.read_text()
+    assert list(runner.events)
+    assert 'hello_world_marker' in list(runner.events)[0]['stdout']
 
 
 @pytest.mark.parametrize('runner_mode', ['pexpect', 'subprocess'])
 def test_stdout_file_no_write(rc, runner_mode):
-    rc.command = ['echo', 'hello_world_marker']
+    rc.command = ['echo', 'hello_world_marker ']  # workaround bug in stdout handl wrapper
     rc.runner_mode = runner_mode
     rc.suppress_output_file = True
-    status, exitcode = Runner(config=rc).run()
+    runner = Runner(config=rc)
+    status, exitcode = runner.run()
     assert status == 'successful'
     for filename in ('stdout', 'stderr'):
         stdout_path = Path(rc.artifact_dir) / filename
         assert not stdout_path.exists()
+    assert list(runner.events)
+    assert 'hello_world_marker' in list(runner.events)[0]['stdout']