Comment 0 for bug 1659055

In most modules of the DPM Nova driver, there are logging calls that format the string on the caller's side, like in this code (link: https://github.com/openstack/nova-dpm/blob/886fa3ae007589de2d41d7b345ae105cdc72c6bb/nova_dpm/virt/dpm/driver.py#L62):

    LOG.debug("HMC details %(zhmc)s %(userid)s"
              % {'zhmc': zhmc, 'userid': userid})

This happens in:

    nova_dpm/virt/dpm/driver.py
    nova_dpm/virt/dpm/host.py
    nova_dpm/virt/dpm/vm.py

The issue with this is that the formatting takes place in any case, even if logging is not turned on at all. This is not a huge performance impact, but it should be cleaned up at some point.

What should be done instead is to pass the format string (using old-style percent-formatting) and the values as separate arguments. There is a number of good ways to pass the values:

As keyword arguments (if the values are in separate variables):

    LOG.debug("HMC details %(zhmc)s %(userid)s",
              zhmc=zhmc, userid=userid)

As positional arguments (if the values are in separate variables):

    LOG.debug("HMC details %s %s", zhmc, userid)

As a dictionary that gets expanded to keyword arguments (if the values are in that dictionary already):

    LOG.debug("HMC details %(zhmc)s %(userid)s", **mydict)

where in this example the dictionary mydict exists even if that log call would not be made, and has items with keys 'zhmc' and 'userid'.

IMO, it is a bad practice (because it is too complex) to build up a dictionary just for the purpose of passing it to the logging call, as shown here:

    LOG.debug("HMC details %(zhmc)s %(userid)s",
              **{'zhmc': zhmc, 'userid': userid})