Missing Placeholders in Log Statements in SharedLibs.py

[chludwig-haufe]

Describe the bug
The log statements in pipx/SharedLiby.py, lines 42 and 44, have extra arguments; the log strings do not contain any placeholders, though. This makes the logging library report an error.

How to reproduce

Here's an excerpt of the docker build output of the Dockerfile statement RUN python3 -m pip install --user pipx && pipx install --verbose "poetry==${POETRY_VERSION}":

Step 6/7 : RUN python3 -m pip install --user pipx &&   pipx install --verbose "poetry==${POETRY_VERSION}"


 ---> Running in 4aee935fadfe

Collecting pipx

  Downloading https://files.pythonhosted.org/packages/bd/16/4dd481c913d748928df79a78dfbf6ce3f42ec5382b630d78f3fd0ef0d8bd/pipx-0.14.0.0-py3-none-any.whl

Collecting userpath

  Downloading https://files.pythonhosted.org/packages/8a/72/07927efb668a0aa0cef502dbe4da442ac9598f19344bca9a3eb9bd062ec1/userpath-1.3.0-py2.py3-none-any.whl

Collecting argcomplete<2.0,>=1.9.4

  Downloading https://files.pythonhosted.org/packages/4d/82/f44c9661e479207348a979b1f6f063625d11dc4ca6256af053719bbb0124/argcomplete-1.10.0-py2.py3-none-any.whl

Collecting click

  Downloading https://files.pythonhosted.org/packages/fa/37/45185cb5abbc30d7257104c434fe0b07e5a195a6847506c074527aa599ec/Click-7.0-py2.py3-none-any.whl (81kB)

Collecting distro; platform_system == "Linux"

  Downloading https://files.pythonhosted.org/packages/ea/35/82f79b92fa4d937146c660a6482cee4f3dfa1f97ff3d2a6f3ecba33e712e/distro-1.4.0-py2.py3-none-any.whl

Installing collected packages: click, distro, userpath, argcomplete, pipx

Successfully installed argcomplete-1.10.0 click-7.0 distro-1.4.0 pipx-0.14.0.0 userpath-1.3.0

pipx > (mkdir:29): creating directory /home/gitlab-runner/.local/pipx/venvs
pipx > (mkdir:29): creating directory /home/gitlab-runner/.local/pipx/.cache
pipx > (run_pipx_command:134): Virtual Environment location is /home/gitlab-runner/.local/pipx/venvs/poetry==1.0.0b2
pipx > (run:97): running /usr/local/bin/python3 -m venv --without-pip /home/gitlab-runner/.local/pipx/venvs/poetry==1.0.0b2

pipx > (run:97): running /usr/local/bin/python3 -m venv /home/gitlab-runner/.local/pipx/shared

--- Logging error ---
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1025, in emit
    msg = self.format(record)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 869, in format
    return fmt.format(record)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 608, in format
    record.message = record.getMessage()
  File "/usr/local/lib/python3.7/logging/__init__.py", line 369, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "/home/gitlab-runner/.local/bin/pipx", line 8, in <module>
    sys.exit(cli())
  File "/home/gitlab-runner/.local/lib/python3.7/site-packages/pipx/main.py", line 547, in cli
    exit(run_pipx_command(parsed_pipx_args))
  File "/home/gitlab-runner/.local/lib/python3.7/site-packages/pipx/main.py", line 166, in run_pipx_command
    include_dependencies=args.include_deps,
  File "/home/gitlab-runner/.local/lib/python3.7/site-packages/pipx/commands.py", line 315, in install
    venv.create_venv(venv_args, pip_args)
  File "/home/gitlab-runner/.local/lib/python3.7/site-packages/pipx/Venv.py", line 117, in create_venv
    shared_libs.create(pip_args, self.verbose)
  File "/home/gitlab-runner/.local/lib/python3.7/site-packages/pipx/SharedLibs.py", line 30, in create
    self.upgrade(pip_args, verbose)
  File "/home/gitlab-runner/.local/lib/python3.7/site-packages/pipx/SharedLibs.py", line 44, in upgrade
    logging.info("Upgrading shared libraries in", self.root)
Message: 'Upgrading shared libraries in'
Arguments: (PosixPath('/home/gitlab-runner/.local/pipx/shared'),)
pipx > (run:97): running /home/gitlab-runner/.local/pipx/shared/bin/python -m pip --disable-pip-version-check install --upgrade pip setuptools wheel

Collecting pip

  Downloading https://files.pythonhosted.org/packages/00/b6/9cfa56b4081ad13874b0c6f96af8ce16cfbc1cb06bedf8e9164ce5551ec1/pip-19.3.1-py2.py3-none-any.whl (1.4MB)

Expected behavior

The log statements should be output w/o error. For this, the logger calls should be changed in line 42 to logging.info("Already upgraded libraries in %s", self.root) and in line 44 to logging.info("Upgrading shared libraries in %s", self.root)

[itsayellow]

I was going to dive right in and fix this, but now I see a bunch of the pipx logging code uses f-strings instead of %s substitution. @cs01 do you have an opinion on this? Historically logging has used the %s-formatted strings for efficiency, but I'm thinking we should be consistent.

[cs01]

I was going to dive right in and fix this, but now I see a bunch of the pipx logging code uses f-strings instead of %s substitution. @cs01 do you have an opinion on this? Historically logging has used the %s-formatted strings for efficiency, but I'm thinking we should be consistent.

f-strings over %s.

The reason being f-strings are easier to read/write and from what I've read in discussions at work is actually more performant than alternatives since they use the FORMAT_VALUE bytecode operation rather than the BINARY_MODULO or CALL_FUNCTION used in %s or .format().

And even if the log level is suppressed, a call tologging.info still needs to be made, and the overhead of that is usually orders of magnitude larger than the wasted f-string interpolation.

Of course in pipx, the number of logging calls is so small that none of this matters anyway.