DRAFT: Redesign test_subprocess logic

[abhaasgoyal]

Resolves #181

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Comparison is base (e3f1f9e) 59.65% compared to head (ce3f15f) 59.34%.
Report is 11 commits behind head on main.

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #253      +/-   ##
==========================================
- Coverage   59.65%   59.34%   -0.32%     
==========================================
  Files          30       30              
  Lines        2191     2184       -7     
==========================================
- Hits         1307     1296      -11     
- Misses        884      888       +4     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[ccarouge]

I'm not particularly sold on the design. It is quite convoluted and I don't think it improves readability. I haven't decided yet if it would improve the development of new tests or not. I have no idea if another design with parameterization is possible or not. I'm just worried this takes things a bit too far.

[bschroeter]

There are a couple of things to consider here. Verbosity can affect both the logging from benchcab AND the printing of commands inside subprocess.py prior to running a command and then capturing the standard out of each command.

With that in mind, this test needs to be reworked.

Testing subprocess verbosity is not just to do with logging, but we also want to log that from the benchcab perspective.

For instance, in subprocess.py we do that following:

if verbose:
    print(cmd)

proc = subprocess.run(cmd, shell=True, check=True, **kwargs)

Verbose is derived from the logging effective level, comments to come in another PR.

And then we test that both the print statement and the subprocess.stdout produce expected results. However, these are conceptually 2 different streams of output: the log (which has a timestamp), and the stdout result of the subprocess command, where we don't want the timestamp.

Really, I think we should be changing the command to something like.

(In subprocess.py)

if verbose:
    get_logger().debug(cmd)
    cmd = f'set -x && {cmd}'

proc = subprocess.run(cmd, shell=True, check=True, **kwargs)

That way we can test the following, as the subprocess PIPE is single use and has it's own execution context (theoretically, assuming the log verbosity has been set):

result = subprocess.run_cmd('echo foo', )
expected = '+ echo foo\nfoo'

This will use standard UNIX debugging functionality, while avoiding the use of a proceeding echo.

This is theoretical, you'll have to test it to see if it works...