Bugs related to logger

[abhaasgoyal]

As of now, the logger is not being used properly in the codebase / has existing bugs.

Current issues

• [ ] render_job_script in pbs.py has verbose as a parameter, which would currently always be false. See https://github.com/CABLE-LSM/benchcab/pull/136#issuecomment-1970152872 for the appropriate steps.
• [ ] subprocess.py is currently using print, when it should either be using logger / printing the command during the subprocess itself / other solutions. See https://github.com/CABLE-LSM/benchcab/pull/253#issuecomment-1970111682 for a potential solution (which prints the command within subprocess.py using set -ex. A better method could be printing the command in the logger only. While implementing the solution, the corresponding tests could use caplog instead of capturing from capfd (they only check for file descriptors 1 and 2 and not the output from logger by default)
• [x] #280

[bschroeter]

OK, to provide some additional context here, I think we need to take a look at the code that redirects printing to standard out in subprocess.py.

https://github.com/CABLE-LSM/benchcab/blob/94824588d92727aa396acf0298166dc00eacb341/benchcab/utils/subprocess.py#L60-L80

I think that we can basically remove the bits that do the standard out catches of print statements and fall back onto using the native subprocess functionality to capture output from commands.

Now that I have a better understanding of this issue, prefixing set -x && to the command is not the correct approach, particularly if we are doing a log.debug() immediately prior. We should be relying on the logger to output commands in verbose mode, and leave the subprocess module to do its thing. We get no additional benefit by printing out the statement inside the subprocess call.

@SeanBryan51 can probably provide additional context here, as I believe he is most suited to comment being the author of this chunk of code.

With these comments added, I am going to un-assign myself as I am working on other tasks and I'm not sure when I'll be available to work on this one - particularly if it becomes a blocker. @ccarouge, please feel free to re-assign me if needed. It isn't a great deal of work to address this issue.

[SeanBryan51]

I think the redirection of subprocess output to stdout was done so that buffering the output wasn't required (this lets us see the output of subprocess commands in real time):

https://github.com/CABLE-LSM/benchcab/blob/94824588d92727aa396acf0298166dc00eacb341/benchcab/utils/subprocess.py#L77

If the intention is to redirect the subprocess output to the logger, this SO post might be relevant: https://stackoverflow.com/questions/21953835/run-subprocess-and-print-output-to-logging

I'm not too sure exactly what the context is for this issue so I'm not sure if this helps, @abhaasgoyal can you update the issue description?

[abhaasgoyal]

@SeanBryan51 I have added the description for the issue. Let me know if anything's unclear.