René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"Git.execute debug message has misleading Popen(shell=...)","articleBody":"While investigating #1685, I noticed that in the debug logging `Git.execute` does to offer insight on the `Popen` call it is about to make, a user inspecting the log would reasonably infer false information about the value passed as the `shell=` keyword argument.\r\n\r\nThe log message is presented as giving information about how `Popen` is being called, not how `Git.execute` has been called: the message shows `Popen(...)`. 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 to `Popen` in cases where a user reading the log would otherwise be misled into thinking this is what has happened.\r\n\r\nReporting the actual `shell=` argument passed to `Popen` is also more useful to log than the argument passed to `Git.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.\r\n\r\nI am not arguing that the logged `Popen(...)` 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 an `istream_ok` string representing the most useful information about how the `istream` argument to `Git.execute` affects what is passed as the `stdin` argument to `Popen`. (It may be that this should be logged as `stdin`, I'm not sure.) These are not misleading.\r\n\r\nIt may be that knowledge that `shell=None` is not a correct thing to pass to `Popen` mitigates this. But `Popen` 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 to `Popen` here: doing so would have revealed #1685 (assuming inspection of the log with `Git.USE_SHELL` set to `True`). 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 show `False` even when `True` is passed.\r\n\r\n### Possible solutions\r\n\r\nCurrently, when `shell` is implicitly or explicitly `None`, the log shows lines of the form (with the `...` filled in):\r\n\r\n```python\r\nPopen(..., shell=None, ...)\r\n```\r\n\r\nI think the best approach is the simple one. This and #1685 can be fixed together by setting the `shell` variable to `self.USE_SHELL` when `shell` started out as `None`, then using `shell` both the `log.debug` and the `Popen` calls. In the log, that would give, assuming `USE_SHELL` is its default `False` value:\r\n\r\n```python\r\nPopen(..., shell=False, ...)\r\n```\r\n\r\nHowever, we could show both:\r\n\r\n```python\r\nPopen(..., shell=False [from: None], ...)\r\n```\r\n\r\nA 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.\r\n\r\nI've opened #1687, which fixes this (along with #1685) in the first way.","author":{"url":"https://github.com/EliahKagan","@type":"Person","name":"EliahKagan"},"datePublished":"2023-10-02T09:20:52.000Z","interactionStatistic":{"@type":"InteractionCounter","interactionType":"https://schema.org/CommentAction","userInteractionCount":2},"url":"https://github.com/1686/GitPython/issues/1686"}