[BUG] Logging output error for logging.DEBUG
To Reproduce Add the following lines to tests/test_checks.py
import logging
logging.basicConfig(level=logging.DEBUG)
The file produces many logging errors
Expected behavior logging should not throw errors
I cannot reproduce this. Here is what I see:
=========================================================================================== 2 passed, 2 skipped in 2.49s ===========================================================================================
(env_k) faridyagubbayli@Mac tests % pytest -s -v -o log_cli=True test_checks.py
=============================================================================================== test session starts ================================================================================================
platform darwin -- Python 3.11.9, pytest-8.2.2, pluggy-1.5.0 -- ~/miniconda3/envs/env_k/bin/python
cachedir: .pytest_cache
rootdir: ..../k-wave-python
configfile: pyproject.toml
plugins: jaxtyping-0.2.30, typeguard-2.13.3
collected 4 items
test_checks.py::TestUltrasoundSimulation::test_simulation_cpu_none PASSED
test_checks.py::TestUltrasoundSimulation::test_simulation_cpu_omp PASSED
test_checks.py::TestUltrasoundSimulation::test_simulation_gpu_cuda SKIPPED (GPU simulations are currently not supported on MacOS)
test_checks.py::TestUltrasoundSimulation::test_simulation_gpu_none SKIPPED (GPU simulations are currently not supported on MacOS)
=========================================================================================== 2 passed, 2 skipped in 2.62s ===========================================================================================
(
Can this be happening only for the GPU simulations?
Tried on Linux with a GPU and still don't see any logging errors.
(env_k) **@***:~/projects/k/k-wave-python/tests$ pytest -s -v -o log_cli=True test_checks.py
================================================================================================ test session starts =================================================================================================
platform linux -- Python 3.11.9, pytest-8.2.2, pluggy-1.5.0 -- ~miniconda3/envs/env_k/bin/python
cachedir: .pytest_cache
rootdir: .../k-wave-python
configfile: pyproject.toml
plugins: jaxtyping-0.2.30, typeguard-2.13.3
collected 4 items
test_checks.py::TestUltrasoundSimulation::test_simulation_cpu_none PASSED
test_checks.py::TestUltrasoundSimulation::test_simulation_cpu_omp PASSED
test_checks.py::TestUltrasoundSimulation::test_simulation_gpu_cuda PASSED
test_checks.py::TestUltrasoundSimulation::test_simulation_gpu_none PASSED
================================================================================================= 4 passed in 7.72s ==================================================================================================
@waltsims can you share the errors you see?
You have to add the lines above to the test file to turn on DEBUG logging:
============================= test session starts ==============================
platform darwin -- Python 3.9.13, pytest-7.1.2, pluggy-1.0.0
rootdir: /Users/walters/git/k-wave-python, configfile: pyproject.toml
plugins: anyio-3.6.1, pyfakefs-5.5.0, jaxtyping-0.2.30, typeguard-2.13.3, cov-4.0.0
collected 4 items
tests/test_checks.py FFss [100%]
=================================== FAILURES ===================================
______________ TestUltrasoundSimulation.test_simulation_cpu_none _______________
self = <tests.test_checks.TestUltrasoundSimulation testMethod=test_simulation_cpu_none>
mock_run_simulation = <MagicMock name='run_simulation' id='13284403232'>
@patch("kwave.kspaceFirstOrder2D.Executor.run_simulation")
def test_simulation_cpu_none(self, mock_run_simulation):
mock_run_simulation.return_value = None
> self._test_simulation(mock_run_simulation, is_gpu_simulation=False, binary_name=None)
tests/test_checks.py:120:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
tests/test_checks.py:140: in _test_simulation
self.run_simulation(is_gpu_simulation=is_gpu_simulation, binary_name=binary_name)
tests/test_checks.py:108: in run_simulation
_ = kspaceFirstOrder2D(
kwave/kspaceFirstOrder2D.py:297: in kspaceFirstOrder2D
k_sim.input_checking("kspaceFirstOrder2D")
kwave/kWaveSimulation.py:494: in input_checking
self.c_ref, self.c_ref_compression, self.c_ref_shear = set_sound_speed_ref(self.medium, opt.simulation_type)
kwave/kWaveSimulation_helper/set_sound_speed_ref.py:19: in set_sound_speed_ref
return get_ordinary_sound_speed_ref(medium)
kwave/kWaveSimulation_helper/set_sound_speed_ref.py:38: in get_ordinary_sound_speed_ref
c_ref = _get_sound_speed_ref(medium.sound_speed_ref, medium.sound_speed)
kwave/kWaveSimulation_helper/set_sound_speed_ref.py:89: in _get_sound_speed_ref
logging.log(logging.INFO, " reference sound speed: ", c_ref, "m/s")
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:2117: in log
root.log(level, msg, *args, **kwargs)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1512: in log
self._log(level, msg, args, **kwargs)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1589: in _log
self.handle(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1599: in handle
self.callHandlers(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1661: in callHandlers
hdlr.handle(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:952: in handle
self.emit(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/logging.py:342: in emit
super().emit(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1091: in emit
self.handleError(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1083: in emit
msg = self.format(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:927: in format
return fmt.format(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/logging.py:113: in format
return super().format(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:663: in format
record.message = record.getMessage()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <LogRecord: root, 20, /Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py, 89, " reference sound speed: ">
def getMessage(self):
"""
Return the message for this LogRecord.
Return the message for this LogRecord after merging any user-supplied
arguments with the message.
"""
msg = str(self.msg)
if self.args:
> msg = msg % self.args
E TypeError: not all arguments converted during string formatting
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:367: TypeError
----------------------------- Captured stderr call -----------------------------
INFO:root: start time: 02-Jul-2024-10-01-34
INFO:root:Running k-Wave simulation...
INFO:root: start time: 02-Jul-2024-10-01-34
--- Logging error ---
Traceback (most recent call last):
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 1083, in emit
msg = self.format(record)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 927, in format
return fmt.format(record)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 663, in format
record.message = record.getMessage()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 367, in getMessage
msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 145, in <module>
pytest.main([__file__])
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/config/__init__.py", line 164, in main
ret: Union[ExitCode, int] = config.hook.pytest_cmdline_main(
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 315, in pytest_cmdline_main
return wrap_session(config, _main)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 268, in wrap_session
session.exitstatus = doit(config, session) or 0
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 322, in _main
config.hook.pytest_runtestloop(session=session)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 347, in pytest_runtestloop
item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 111, in pytest_runtest_protocol
runtestprotocol(item, nextitem=nextitem)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 130, in runtestprotocol
reports.append(call_and_report(item, "call", log))
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 219, in call_and_report
call = call_runtest_hook(item, when, **kwds)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 258, in call_runtest_hook
return CallInfo.from_call(
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 338, in from_call
result: Optional[TResult] = func()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 259, in <lambda>
lambda: ihook(item=item, **kwds), when=when, reraise=reraise
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 166, in pytest_runtest_call
item.runtest()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/unittest.py", line 327, in runtest
self._testcase(result=self) # type: ignore[arg-type]
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/case.py", line 651, in __call__
return self.run(*args, **kwds)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/case.py", line 592, in run
self._callTestMethod(testMethod)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/case.py", line 550, in _callTestMethod
method()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/mock.py", line 1336, in patched
return func(*newargs, **newkeywargs)
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 120, in test_simulation_cpu_none
self._test_simulation(mock_run_simulation, is_gpu_simulation=False, binary_name=None)
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 140, in _test_simulation
self.run_simulation(is_gpu_simulation=is_gpu_simulation, binary_name=binary_name)
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 108, in run_simulation
_ = kspaceFirstOrder2D(
File "/Users/walters/git/k-wave-python/kwave/kspaceFirstOrder2D.py", line 297, in kspaceFirstOrder2D
k_sim.input_checking("kspaceFirstOrder2D")
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation.py", line 494, in input_checking
self.c_ref, self.c_ref_compression, self.c_ref_shear = set_sound_speed_ref(self.medium, opt.simulation_type)
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py", line 19, in set_sound_speed_ref
return get_ordinary_sound_speed_ref(medium)
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py", line 38, in get_ordinary_sound_speed_ref
c_ref = _get_sound_speed_ref(medium.sound_speed_ref, medium.sound_speed)
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py", line 89, in _get_sound_speed_ref
logging.log(logging.INFO, " reference sound speed: ", c_ref, "m/s")
Message: ' reference sound speed: '
Arguments: (1000, 'm/s')
------------------------------ Captured log call -------------------------------
INFO root:kWaveSimulation.py:107 start time: 02-Jul-2024-10-01-34
INFO root:kWaveSimulation.py:553 Running k-Wave simulation...
INFO root:kWaveSimulation.py:554 start time: 02-Jul-2024-10-01-34
_______________ TestUltrasoundSimulation.test_simulation_cpu_omp _______________
self = <tests.test_checks.TestUltrasoundSimulation testMethod=test_simulation_cpu_omp>
mock_run_simulation = <MagicMock name='run_simulation' id='13527565984'>
@patch("kwave.kspaceFirstOrder2D.Executor.run_simulation")
def test_simulation_cpu_omp(self, mock_run_simulation):
mock_run_simulation.return_value = None
> self._test_simulation(mock_run_simulation, is_gpu_simulation=False, binary_name="kspaceFirstOrder-OMP")
tests/test_checks.py:137:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
tests/test_checks.py:140: in _test_simulation
self.run_simulation(is_gpu_simulation=is_gpu_simulation, binary_name=binary_name)
tests/test_checks.py:108: in run_simulation
_ = kspaceFirstOrder2D(
kwave/kspaceFirstOrder2D.py:297: in kspaceFirstOrder2D
k_sim.input_checking("kspaceFirstOrder2D")
kwave/kWaveSimulation.py:494: in input_checking
self.c_ref, self.c_ref_compression, self.c_ref_shear = set_sound_speed_ref(self.medium, opt.simulation_type)
kwave/kWaveSimulation_helper/set_sound_speed_ref.py:19: in set_sound_speed_ref
return get_ordinary_sound_speed_ref(medium)
kwave/kWaveSimulation_helper/set_sound_speed_ref.py:38: in get_ordinary_sound_speed_ref
c_ref = _get_sound_speed_ref(medium.sound_speed_ref, medium.sound_speed)
kwave/kWaveSimulation_helper/set_sound_speed_ref.py:89: in _get_sound_speed_ref
logging.log(logging.INFO, " reference sound speed: ", c_ref, "m/s")
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:2117: in log
root.log(level, msg, *args, **kwargs)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1512: in log
self._log(level, msg, args, **kwargs)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1589: in _log
self.handle(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1599: in handle
self.callHandlers(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1661: in callHandlers
hdlr.handle(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:952: in handle
self.emit(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/logging.py:342: in emit
super().emit(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1091: in emit
self.handleError(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:1083: in emit
msg = self.format(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:927: in format
return fmt.format(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/logging.py:113: in format
return super().format(record)
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:663: in format
record.message = record.getMessage()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <LogRecord: root, 20, /Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py, 89, " reference sound speed: ">
def getMessage(self):
"""
Return the message for this LogRecord.
Return the message for this LogRecord after merging any user-supplied
arguments with the message.
"""
msg = str(self.msg)
if self.args:
> msg = msg % self.args
E TypeError: not all arguments converted during string formatting
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py:367: TypeError
----------------------------- Captured stderr call -----------------------------
INFO:root: start time: 02-Jul-2024-10-01-34
INFO:root:Running k-Wave simulation...
INFO:root: start time: 02-Jul-2024-10-01-34
--- Logging error ---
Traceback (most recent call last):
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 1083, in emit
msg = self.format(record)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 927, in format
return fmt.format(record)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 663, in format
record.message = record.getMessage()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/logging/__init__.py", line 367, in getMessage
msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 145, in <module>
pytest.main([__file__])
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/config/__init__.py", line 164, in main
ret: Union[ExitCode, int] = config.hook.pytest_cmdline_main(
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 315, in pytest_cmdline_main
return wrap_session(config, _main)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 268, in wrap_session
session.exitstatus = doit(config, session) or 0
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 322, in _main
config.hook.pytest_runtestloop(session=session)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/main.py", line 347, in pytest_runtestloop
item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 111, in pytest_runtest_protocol
runtestprotocol(item, nextitem=nextitem)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 130, in runtestprotocol
reports.append(call_and_report(item, "call", log))
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 219, in call_and_report
call = call_runtest_hook(item, when, **kwds)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 258, in call_runtest_hook
return CallInfo.from_call(
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 338, in from_call
result: Optional[TResult] = func()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 259, in <lambda>
lambda: ihook(item=item, **kwds), when=when, reraise=reraise
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_hooks.py", line 265, in __call__
return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_manager.py", line 80, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/pluggy/_callers.py", line 39, in _multicall
res = hook_impl.function(*args)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/runner.py", line 166, in pytest_runtest_call
item.runtest()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/unittest.py", line 327, in runtest
self._testcase(result=self) # type: ignore[arg-type]
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/case.py", line 651, in __call__
return self.run(*args, **kwds)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/case.py", line 592, in run
self._callTestMethod(testMethod)
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/case.py", line 550, in _callTestMethod
method()
File "/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/unittest/mock.py", line 1336, in patched
return func(*newargs, **newkeywargs)
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 137, in test_simulation_cpu_omp
self._test_simulation(mock_run_simulation, is_gpu_simulation=False, binary_name="kspaceFirstOrder-OMP")
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 140, in _test_simulation
self.run_simulation(is_gpu_simulation=is_gpu_simulation, binary_name=binary_name)
File "/Users/walters/git/k-wave-python/tests/test_checks.py", line 108, in run_simulation
_ = kspaceFirstOrder2D(
File "/Users/walters/git/k-wave-python/kwave/kspaceFirstOrder2D.py", line 297, in kspaceFirstOrder2D
k_sim.input_checking("kspaceFirstOrder2D")
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation.py", line 494, in input_checking
self.c_ref, self.c_ref_compression, self.c_ref_shear = set_sound_speed_ref(self.medium, opt.simulation_type)
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py", line 19, in set_sound_speed_ref
return get_ordinary_sound_speed_ref(medium)
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py", line 38, in get_ordinary_sound_speed_ref
c_ref = _get_sound_speed_ref(medium.sound_speed_ref, medium.sound_speed)
File "/Users/walters/git/k-wave-python/kwave/kWaveSimulation_helper/set_sound_speed_ref.py", line 89, in _get_sound_speed_ref
logging.log(logging.INFO, " reference sound speed: ", c_ref, "m/s")
Message: ' reference sound speed: '
Arguments: (1000, 'm/s')
------------------------------ Captured log call -------------------------------
INFO root:kWaveSimulation.py:107 start time: 02-Jul-2024-10-01-34
INFO root:kWaveSimulation.py:553 Running k-Wave simulation...
INFO root:kWaveSimulation.py:554 start time: 02-Jul-2024-10-01-34
=============================== warnings summary ===============================
../../../../opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/config/__init__.py:1129
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/config/__init__.py:1129: PytestAssertRewriteWarning: Module already imported so cannot be rewritten: jaxtyping
self._mark_plugins_for_rewrite(hook)
-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=========================== short test summary info ============================
FAILED tests/test_checks.py::TestUltrasoundSimulation::test_simulation_cpu_none
FAILED tests/test_checks.py::TestUltrasoundSimulation::test_simulation_cpu_omp
=================== 2 failed, 2 skipped, 1 warning in 0.53s ====================
Without adding those lines to the test file, I get the same output as you:
============================= test session starts ==============================
platform darwin -- Python 3.9.13, pytest-7.1.2, pluggy-1.0.0
rootdir: /Users/walters/git/k-wave-python, configfile: pyproject.toml
plugins: anyio-3.6.1, pyfakefs-5.5.0, jaxtyping-0.2.30, typeguard-2.13.3, cov-4.0.0
collected 4 items
tests/test_checks.py ..ss [100%]
=============================== warnings summary ===============================
../../../../opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/config/__init__.py:1129
/opt/homebrew/Caskroom/miniforge/base/envs/k-wave-python/lib/python3.9/site-packages/_pytest/config/__init__.py:1129: PytestAssertRewriteWarning: Module already imported so cannot be rewritten: jaxtyping
self._mark_plugins_for_rewrite(hook)
-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=================== 2 passed, 2 skipped, 1 warning in 2.69s ====================
@waltsims I tried to reproduce this with Python 3.9 but still not seeing any warning. I have the logging config lines from your instructions. Maybe this is somehow specific to your environment?
Taking this over since @faridyagubbayli cannot reproduce it.