While investigating#1685, I noticed that in the debug loggingGit.execute does to offer insight on thePopen call it is about to make, a user inspecting the log would reasonably infer false information about the value passed as theshell= keyword argument.

The log message is presented as giving information about howPopen is being called, not howGit.execute has been called: the message showsPopen(...). I agree with this and I don't consider it a bug. But this means it should faithfully report what is about to be passed toPopen in cases where a user reading the log would otherwise be misled into thinking this is what has happened.

Reporting the actualshell= argument passed toPopen is also more useful to log than the argument passed toGit.execute (or its default value, as the case may be). Of course, logging both is possible, for example by adding more text like[from: None], though I am somewhat inclined to think that is not worth doing.

I am not arguing that the loggedPopen(...) message needs to only show things as they really are in the call. It already replaces passwords to decrease leakage of sensitive information into logs, and it shows anistream_ok string representing the most useful information about how theistream argument toGit.execute affects what is passed as thestdin argument toPopen. (It may be that this should be logged asstdin, I'm not sure.) These are not misleading.

It may be that knowledge thatshell=None is not a correct thing to pass toPopen mitigates this. ButPopen accepts many arguments, and it's hard to remember what all the possible values are for all of them. Furthermore, I think there is a benefit to logging exactly what is about to be passed toPopen here: doing so would have revealed#1685 (assuming inspection of the log withGit.USE_SHELL set toTrue). The current way is more prone to error, because nontrivial logic follows the logging intended to make that logic's effect clear; so the log can showFalse even whenTrue is passed.

Possible solutions

Currently, whenshell is implicitly or explicitlyNone, the log shows lines of the form (with the... filled in):

Popen(...,shell=None, ...)

I think the best approach is the simple one. This and#1685 can be fixed together by setting theshell variable toself.USE_SHELL whenshell started out asNone, then usingshell both thelog.debug and thePopen calls. In the log, that would give, assumingUSE_SHELL is its defaultFalse value:

Popen(...,shell=False, ...)

However, we could show both:

Popen(...,shell=False [from:None], ...)

A mentioned above, I favor the former, simpler way. But I thought the latter was worth mentioning, because it is another way to show the information without misleading the user.

I've opened#1687, which fixes this (along with#1685) in the first way.