logging TypeError: not all arguments converted during string formatting

[Daiyue Weng]

Hi, I am trying to record memory and CPU usages and load a logger from an
external config file (logging.conf),

[loggers]
keys=root,hardware_log

[handlers]
keys=consoleHandler,hardwareFileHandler

[formatters]
keys=hardwareFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_hardware_log]
level=DEBUG
handlers=hardwareFileHandler
qualname=hardware_log
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=hardwareFormatter
args=(sys.stdout,)

[handler_hardwareFileHandler]
class=handlers.RotatingFileHandler
maxBytes=51200
level=DEBUG
formatter=hardwareFormatter
args=("log/hardware.log",)

[formatter_hardwareFormatter]
format=pathname~%(pathname)s||timestamp~%(asctime)s||level~%(levelname)s||name~%(name)s||function_name~%(funcName)s||line_no~%(lineno)s||debug_CPU~%(message)s||debug_Mem~%(message)s
datefmt=%m/%d/%Y %H:%M:%S
class=logging.Formatter


import logging

import psutil

logging.config.fileConfig('logging.conf')

hardware_log = logging.getLogger(HARDWARELOGNAME)

free_mem_gb_pre = psutil.virtual_memory().available / 1000000000.
cpu_util_pct_pre = psutil.cpu_percent()

hardware_log.info(cpu_util_pct_pre, free_mem_gb_pre)


I got the following errors,

--- Logging error ---
Traceback (most recent call last):
File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 980, in emit
msg = self.format(record)
File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 830, in format
return fmt.format(record)
File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 567, in format
record.message = record.getMessage()
File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 330, in getMessage
msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
File "C:\Program Files (x86)\JetBrains\PyCharm
2016.2.1\helpers\pycharm\pytestrunner.py", line 60, in <module>
main()
File "C:\Program Files (x86)\JetBrains\PyCharm
2016.2.1\helpers\pycharm\pytestrunner.py", line 35, in main
exitstatus = hook.pytest_cmdline_main(config=config)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 724, in __call__
return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 338, in _hookexec
return self._inner_hookexec(hook, methods, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 333, in <lambda>
_MultiCall(methods, kwargs, hook.spec_opts).execute()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 596, in execute
res = hook_impl.function(*args)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\main.py",
line 115, in pytest_cmdline_main
return wrap_session(config, _main)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\main.py",
line 90, in wrap_session
session.exitstatus = doit(config, session) or 0
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\main.py",
line 121, in _main
config.hook.pytest_runtestloop(session=session)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 724, in __call__
return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 338, in _hookexec
return self._inner_hookexec(hook, methods, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 333, in <lambda>
_MultiCall(methods, kwargs, hook.spec_opts).execute()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 596, in execute
res = hook_impl.function(*args)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\main.py",
line 146, in pytest_runtestloop
item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 724, in __call__
return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 338, in _hookexec
return self._inner_hookexec(hook, methods, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 333, in <lambda>
_MultiCall(methods, kwargs, hook.spec_opts).execute()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 595, in execute
return _wrapped_call(hook_impl.function(*args), self.execute)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 247, in _wrapped_call
call_outcome = _CallOutcome(func)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 264, in __init__
self.result = func()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 596, in execute
res = hook_impl.function(*args)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 65, in pytest_runtest_protocol
runtestprotocol(item, nextitem=nextitem)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 75, in runtestprotocol
reports.append(call_and_report(item, "call", log))
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 119, in call_and_report
call = call_runtest_hook(item, when, **kwds)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 137, in call_runtest_hook
return CallInfo(lambda: ihook(item=item, **kwds), when=when)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 149, in __init__
self.result = func()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 137, in <lambda>
return CallInfo(lambda: ihook(item=item, **kwds), when=when)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 724, in __call__
return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 338, in _hookexec
return self._inner_hookexec(hook, methods, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 333, in <lambda>
_MultiCall(methods, kwargs, hook.spec_opts).execute()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 595, in execute
return _wrapped_call(hook_impl.function(*args), self.execute)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 247, in _wrapped_call
call_outcome = _CallOutcome(func)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 264, in __init__
self.result = func()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 596, in execute
res = hook_impl.function(*args)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\runner.py",
line 90, in pytest_runtest_call
item.runtest()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\python.py",
line 1406, in runtest
self.ihook.pytest_pyfunc_call(pyfuncitem=self)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 724, in __call__
return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 338, in _hookexec
return self._inner_hookexec(hook, methods, kwargs)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 333, in <lambda>
_MultiCall(methods, kwargs, hook.spec_opts).execute()
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\vendored_packages\pluggy.py",
line 596, in execute
res = hook_impl.function(*args)
File "C:\Continuum\Anaconda3\lib\site-packages\_pytest\python.py",
line 286, in pytest_pyfunc_call
testfunction(**testargs)
File "C:\Users\dweng\PycharmProjects\lumar_ingestion\ingestion_workflows\full_table_workflow_test.py",
line 40, in test_SAP_invoice
tab_output = workflow.execute(tab)
File "C:\Users\dweng\PycharmProjects\lumar_ingestion\ingestion_workflows\full_table_workflow.py",
line 85, in execute
data = workflow.execute(data)
File "C:\Users\dweng\PycharmProjects\lumar_ingestion\Workflow\workflow.py",
line 25, in execute
output = self.steps[0].execute(data)
File "C:\Users\dweng\PycharmProjects\lumar_ingestion\ingestion_workflow_modules\import_to_dataframe.py",
line 61, in execute
hardware_log.info(cpu_util_pct_pre, free_mem_gb_pre)
Message: 38.5
Arguments: (8.87662592,)


How to fix the problem?

cheers

[MRAB]

On 2016-09-15 15:57, Daiyue Weng wrote:
> Hi, I am trying to record memory and CPU usages and load a logger from an
> external config file (logging.conf),
>

[snip]

>
> import logging
>
> import psutil
>
> logging.config.fileConfig('logging.conf')
>
> hardware_log = logging.getLogger(HARDWARELOGNAME)
>
> free_mem_gb_pre = psutil.virtual_memory().available / 1000000000.
> cpu_util_pct_pre = psutil.cpu_percent()
>
> hardware_log.info(cpu_util_pct_pre, free_mem_gb_pre)
>
>
> I got the following errors,
>
> --- Logging error ---
> Traceback (most recent call last):
> File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 980, in emit
> msg = self.format(record)
> File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 830, in format
> return fmt.format(record)
> File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 567, in format
> record.message = record.getMessage()
> File "C:\Continuum\Anaconda3\lib\logging\__init__.py", line 330, in getMessage
> msg = msg % self.args
> TypeError: not all arguments converted during string formatting

[snip]

> File "C:\Users\dweng\PycharmProjects\lumar_ingestion\ingestion_workflow_modules\import_to_dataframe.py",
> line 61, in execute
> hardware_log.info(cpu_util_pct_pre, free_mem_gb_pre)
> Message: 38.5
> Arguments: (8.87662592,)
>
>
> How to fix the problem?
>

The doc for logging.info says:

logging.info(msg, *args, **kwargs)

In this line of your code:

hardware_log.info(cpu_util_pct_pre, free_mem_gb_pre)

you're passing in 2 values.

The first (38.5) is being treated as the message template (a format
string) and the second (8.87662592) as the value to be put into the
template.

What you should be doing is something like:

logging.info('cpu_util_pct_pre is %s, free_mem_gb_pre is %s',
cpu_util_pct_pre, free_mem_gb_pre)

[Peter Otten]

Daiyue Weng wrote:

> Hi, I am trying to record memory and CPU usages and load a logger from an
> external config file (logging.conf),

[snip]

One important debugging strategy is to try and find the minimal example that
produces a problem. In this case you can provoke the the behaviour you are
seeing with two lines of Python:

>>> import logging
>>> logging.warn(1, 2)

--- Logging error ---
Traceback (most recent call last):

File "/usr/lib/python3.4/logging/__init__.py", line 978, in emit
msg = self.format(record)
File "/usr/lib/python3.4/logging/__init__.py", line 828, in format
return fmt.format(record)
File "/usr/lib/python3.4/logging/__init__.py", line 565, in format
record.message = record.getMessage()
File "/usr/lib/python3.4/logging/__init__.py", line 328, in getMessage

msg = msg % self.args
TypeError: not all arguments converted during string formatting

Call stack:
File "<stdin>", line 1, in <module>
Message: 1
Arguments: (2,)

Please make an effort to remove the irrelevant stuff before you come here to
ask for help next time. Thank you.