peakdet
peakdet copied to clipboard
[WIP] Integrate Loguru
References: https://github.com/physiopy/phys2bids/issues/461
Integrate Loguru for all log types, including info messages, warnings and exception catching
Proposed Changes
- Migrate all message logging to a single logger interface with Loguru. This includes console
print()
s, warnings and exceptions
Change Type
- [ ]
bugfix
(+0.0.1) - [x]
minor
(+0.1.0) - [ ]
major
(+1.0.0) - [ ]
refactoring
(no version update) - [ ]
test
(no version update) - [ ]
infrastructure
(no version update) - [ ]
documentation
(no version update) - [ ]
other
Checklist before review
- [ ] I added everything I wanted to add to this PR.
- [ ] [Code or tests only] I wrote/updated the necessary docstrings.
- [ ] [Code or tests only] I ran and passed tests locally.
- [ ] [Documentation only] I built the docs locally.
- [x] My contribution is harmonious with the rest of the code: I'm not introducing repetitions.
- [x] My code respects the adopted style, especially linting conventions.
- [x] The title of this PR is explanatory on its own, enough to be understood as part of a changelog.
- [ ] I added or indicated the right labels.
- [ ] I added information regarding the timeline of completion for this PR.
- [ ] Please, comment on my PR while it's a draft and give me feedback on the development!
Regarding dependencies, in this PR I just added loguru to requirements.txt
. However there were still some packages which were missing from my local environment (e.g. gooey, pandas).
Then I saw #53 and found this proposed line:
To install ``peakdet`` along with the basic required modules just run::
pip3 install phys2bids
Why not have such dependencies in the requirements file to not require installing phys2bids
?
Hey @maestroque! Our main way to install things is through pip (specified and regulated by the setup.py
and mainly setup.cfg
files). For devs, you can follow this guide:
https://physiopy.github.io/community/gettingstarted/
When you want to update setups, you can add the required packages in the requirements.txt, but you have to add them in the correct category in the setup.cfg
file.
You do not need to install phys2bids.
Currently the logs for errors are very verbose regarding callbacks. Do we want this or should we opt for something shorter? I attach an example below
2024-05-13 13:45:14.880 | ERROR | peakdet.tests.test_utils:test_check_physio:56 - An error has been caught in function 'test_check_physio', process 'MainProcess' (6353), thread 'MainThread' (139793792565312):
Traceback (most recent call last):
File "/home/maestroque/repos/peakdet/peak-new/bin/pytest", line 8, in <module>
sys.exit(console_main())
│ │ └ <function console_main at 0x7f2445c64ae0>
│ └ <built-in function exit>
└ <module 'sys' (built-in)>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/config/__init__.py", line 197, in console_main
code = main()
└ <function main at 0x7f2445c649a0>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/config/__init__.py", line 174, in main
ret: Union[ExitCode, int] = config.hook.pytest_cmdline_main(
│ │ │ │ └ <HookCaller 'pytest_cmdline_main'>
│ │ │ └ <_pytest.config.compat.PathAwareHookProxy object at 0x7f24458d29d0>
│ │ └ <_pytest.config.Config object at 0x7f24458d2790>
│ └ <enum 'ExitCode'>
└ typing.Union
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_hooks.py", line 501, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
│ │ │ │ │ │ │ └ True
│ │ │ │ │ │ └ {'config': <_pytest.config.Config object at 0x7f24458d2790>}
│ │ │ │ │ └ <member '_hookimpls' of 'HookCaller' objects>
│ │ │ │ └ <HookCaller 'pytest_cmdline_main'>
│ │ │ └ <member 'name' of 'HookCaller' objects>
│ │ └ <HookCaller 'pytest_cmdline_main'>
│ └ <member '_hookexec' of 'HookCaller' objects>
└ <HookCaller 'pytest_cmdline_main'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_manager.py", line 119, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
│ │ │ │ │ └ True
│ │ │ │ └ {'config': <_pytest.config.Config object at 0x7f24458d2790>}
│ │ │ └ [<HookImpl plugin_name='main', plugin=<module '_pytest.main' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/sit...
│ │ └ 'pytest_cmdline_main'
│ └ <function _multicall at 0x7f244617efc0>
└ <_pytest.config.PytestPluginManager object at 0x7f2445a2dd50>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_callers.py", line 102, in _multicall
res = hook_impl.function(*args)
│ │ └ [<_pytest.config.Config object at 0x7f24458d2790>]
│ └ <member 'function' of 'HookImpl' objects>
└ <HookImpl plugin_name='main', plugin=<module '_pytest.main' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site...
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/main.py", line 332, in pytest_cmdline_main
return wrap_session(config, _main)
│ │ └ <function _main at 0x7f2445d0d800>
│ └ <_pytest.config.Config object at 0x7f24458d2790>
└ <function wrap_session at 0x7f2445d0d760>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/main.py", line 285, in wrap_session
session.exitstatus = doit(config, session) or 0
│ │ │ │ └ <Session exitstatus=<ExitCode.OK: 0> testsfailed=12 testscollected=22>
│ │ │ └ <_pytest.config.Config object at 0x7f24458d2790>
│ │ └ <function _main at 0x7f2445d0d800>
│ └ <ExitCode.OK: 0>
└ <Session exitstatus=<ExitCode.OK: 0> testsfailed=12 testscollected=22>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/main.py", line 339, in _main
config.hook.pytest_runtestloop(session=session)
│ │ │ └ <Session exitstatus=<ExitCode.OK: 0> testsfailed=12 testscollected=22>
│ │ └ <HookCaller 'pytest_runtestloop'>
│ └ <_pytest.config.compat.PathAwareHookProxy object at 0x7f24458d29d0>
└ <_pytest.config.Config object at 0x7f24458d2790>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_hooks.py", line 501, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
│ │ │ │ │ │ │ └ True
│ │ │ │ │ │ └ {'session': <Session exitstatus=<ExitCode.OK: 0> testsfailed=12 testscollected=22>}
│ │ │ │ │ └ <member '_hookimpls' of 'HookCaller' objects>
│ │ │ │ └ <HookCaller 'pytest_runtestloop'>
│ │ │ └ <member 'name' of 'HookCaller' objects>
│ │ └ <HookCaller 'pytest_runtestloop'>
│ └ <member '_hookexec' of 'HookCaller' objects>
└ <HookCaller 'pytest_runtestloop'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_manager.py", line 119, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
│ │ │ │ │ └ True
│ │ │ │ └ {'session': <Session exitstatus=<ExitCode.OK: 0> testsfailed=12 testscollected=22>}
│ │ │ └ [<HookImpl plugin_name='main', plugin=<module '_pytest.main' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/sit...
│ │ └ 'pytest_runtestloop'
│ └ <function _multicall at 0x7f244617efc0>
└ <_pytest.config.PytestPluginManager object at 0x7f2445a2dd50>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_callers.py", line 102, in _multicall
res = hook_impl.function(*args)
│ │ └ [<Session exitstatus=<ExitCode.OK: 0> testsfailed=12 testscollected=22>]
│ └ <member 'function' of 'HookImpl' objects>
└ <HookImpl plugin_name='main', plugin=<module '_pytest.main' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site...
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/main.py", line 364, in pytest_runtestloop
item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
│ │ │ └ <Function test_new_physio_like>
│ │ └ <Function test_check_physio>
│ └ <member 'config' of 'Node' objects>
└ <Function test_check_physio>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_hooks.py", line 501, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
│ │ │ │ │ │ │ └ True
│ │ │ │ │ │ └ {'item': <Function test_check_physio>, 'nextitem': <Function test_new_physio_like>}
│ │ │ │ │ └ <member '_hookimpls' of 'HookCaller' objects>
│ │ │ │ └ <HookCaller 'pytest_runtest_protocol'>
│ │ │ └ <member 'name' of 'HookCaller' objects>
│ │ └ <HookCaller 'pytest_runtest_protocol'>
│ └ <member '_hookexec' of 'HookCaller' objects>
└ <HookCaller 'pytest_runtest_protocol'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_manager.py", line 119, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
│ │ │ │ │ └ True
│ │ │ │ └ {'item': <Function test_check_physio>, 'nextitem': <Function test_new_physio_like>}
│ │ │ └ [<HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11...
│ │ └ 'pytest_runtest_protocol'
│ └ <function _multicall at 0x7f244617efc0>
└ <_pytest.config.PytestPluginManager object at 0x7f2445a2dd50>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_callers.py", line 102, in _multicall
res = hook_impl.function(*args)
│ │ └ [<Function test_check_physio>, <Function test_new_physio_like>]
│ └ <member 'function' of 'HookImpl' objects>
└ <HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/...
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/runner.py", line 115, in pytest_runtest_protocol
runtestprotocol(item, nextitem=nextitem)
│ │ └ <Function test_new_physio_like>
│ └ <Function test_check_physio>
└ <function runtestprotocol at 0x7f2445d0c9a0>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/runner.py", line 134, in runtestprotocol
reports.append(call_and_report(item, "call", log))
│ │ │ │ └ True
│ │ │ └ <Function test_check_physio>
│ │ └ <function call_and_report at 0x7f2445d0ce00>
│ └ <method 'append' of 'list' objects>
└ [<TestReport 'peakdet/tests/test_utils.py::test_check_physio' when='setup' outcome='passed'>]
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/runner.py", line 239, in call_and_report
call = CallInfo.from_call(
│ └ <classmethod(<function CallInfo.from_call at 0x7f2445d0d120>)>
└ <class '_pytest.runner.CallInfo'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/runner.py", line 340, in from_call
result: Optional[TResult] = func()
│ │ └ <function call_and_report.<locals>.<lambda> at 0x7f2412d76b60>
│ └ +TResult
└ typing.Optional
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/runner.py", line 240, in <lambda>
lambda: runtest_hook(item=item, **kwds), when=when, reraise=reraise
│ │ └ {}
│ └ <Function test_check_physio>
└ <HookCaller 'pytest_runtest_call'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_hooks.py", line 501, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
│ │ │ │ │ │ │ └ False
│ │ │ │ │ │ └ {'item': <Function test_check_physio>}
│ │ │ │ │ └ <member '_hookimpls' of 'HookCaller' objects>
│ │ │ │ └ <HookCaller 'pytest_runtest_call'>
│ │ │ └ <member 'name' of 'HookCaller' objects>
│ │ └ <HookCaller 'pytest_runtest_call'>
│ └ <member '_hookexec' of 'HookCaller' objects>
└ <HookCaller 'pytest_runtest_call'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_manager.py", line 119, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
│ │ │ │ │ └ False
│ │ │ │ └ {'item': <Function test_check_physio>}
│ │ │ └ [<HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11...
│ │ └ 'pytest_runtest_call'
│ └ <function _multicall at 0x7f244617efc0>
└ <_pytest.config.PytestPluginManager object at 0x7f2445a2dd50>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_callers.py", line 102, in _multicall
res = hook_impl.function(*args)
│ │ └ [<Function test_check_physio>]
│ └ <member 'function' of 'HookImpl' objects>
└ <HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/...
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/runner.py", line 172, in pytest_runtest_call
item.runtest()
│ └ <function Function.runtest at 0x7f2445c06520>
└ <Function test_check_physio>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/python.py", line 1772, in runtest
self.ihook.pytest_pyfunc_call(pyfuncitem=self)
│ │ └ <Function test_check_physio>
│ └ <property object at 0x7f2445c83880>
└ <Function test_check_physio>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_hooks.py", line 501, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
│ │ │ │ │ │ │ └ True
│ │ │ │ │ │ └ {'pyfuncitem': <Function test_check_physio>}
│ │ │ │ │ └ <member '_hookimpls' of 'HookCaller' objects>
│ │ │ │ └ <HookCaller 'pytest_pyfunc_call'>
│ │ │ └ <member 'name' of 'HookCaller' objects>
│ │ └ <HookCaller 'pytest_pyfunc_call'>
│ └ <member '_hookexec' of 'HookCaller' objects>
└ <HookCaller 'pytest_pyfunc_call'>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_manager.py", line 119, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
│ │ │ │ │ └ True
│ │ │ │ └ {'pyfuncitem': <Function test_check_physio>}
│ │ │ └ [<HookImpl plugin_name='python', plugin=<module '_pytest.python' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11...
│ │ └ 'pytest_pyfunc_call'
│ └ <function _multicall at 0x7f244617efc0>
└ <_pytest.config.PytestPluginManager object at 0x7f2445a2dd50>
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/pluggy/_callers.py", line 102, in _multicall
res = hook_impl.function(*args)
│ │ └ [<Function test_check_physio>]
│ └ <member 'function' of 'HookImpl' objects>
└ <HookImpl plugin_name='python', plugin=<module '_pytest.python' from '/home/maestroque/repos/peakdet/peak-new/lib/python3.11/...
File "/home/maestroque/repos/peakdet/peak-new/lib/python3.11/site-packages/_pytest/python.py", line 195, in pytest_pyfunc_call
result = testfunction(**testargs)
│ └ {}
└ <function test_check_physio at 0x7f2417c61d00>
> File "/home/maestroque/repos/peakdet/peakdet/tests/test_utils.py", line 56, in test_check_physio
utils.check_physio(fname)
│ │ └ '/home/maestroque/repos/peakdet/peakdet/tests/data/ECG.csv'
│ └ <function check_physio at 0x7f241933bba0>
└ <module 'peakdet.utils' from '/home/maestroque/repos/peakdet/peakdet/utils.py'>
File "/home/maestroque/repos/peakdet/peakdet/utils.py", line 142, in check_physio
raise ValueError('Provided data does not have valid sampling rate.')
This seems extremely verbose... Should we give the bare minimum at any level, and then increase the level when a "verbose" CLI call is selected (see phys2bids)?
It can toggled by adding a new logger instance with diagnose
=0. Backtraces can be also toggled but they are either on or off, I couldn't find a backtrace level
For the CLI call it can be done using a parameter as you proposed. The example I sent above was also from pytest outputs which have a lot of backtraces anyways.
Another question is if someone just uses the modules on their own as a library instead of the CLI, should we assume that the user then is responsible for their own logger (check here)? Or do we still use loguru? For the time being I only have it enabled in the CLI and disabled for module use, but the user can explicitly enable it if he wants.
@smoia @m-miedema @me-pic
Another question is if someone just uses the modules on their own as a library instead of the CLI, should we assume that the user then is responsible for their own logger (check here)? Or do we still use loguru? For the time being I only have it enabled in the CLI and disabled for module use, but the user can explicitly enable it if he wants.
That seems sensible to me! Our logging is really meant mainly for the CLI, but consider that it will be a required install once we add it, so our module users should still be able to use it if they want to.
The last issue is that @logger.catch
catches all exceptions and logs them in the loguru format. If the logger is disabled those exceptions do not show for the library user even in the standard non-loguru format.
I would propose for @logger.catch
to be used as a decorator only for the workflow function of the CLI, to avoid this. Then
- CLI users would have everything logged in the loguru format (both logs and exceptions)
- Library users would by default not have loguru enabled. If they enable it, only logs will be in loguru format and exceptions will be in the standard format, except if they add a
@logger.catch
in their own code, as in the snippet below:
with logger.catch():
peakdet.utils.enable_logger(False, True)
data = np.random.rand(5000, 2)
phys = peakdet.Physio(data, 10)
What's your opinion with this? Other than that I believe this PR is ready for review.
Btw a sample log would be something like this with the verbose
setting:
and a sample log without verbose
Again, seems fair to me. @m-miedema @me-pic what do you think?
Looks good to me too ! Good job 🎉
Again, seems fair to me. @m-miedema @me-pic what do you think?
Looks good to me!
List of things for this PR:
- [x] Add more info logs throughout the functions (not on the workflow as it's outdated for the time being)
- [x] Add a file sink, similar to
phys2denoise
- [x] Add loguru as a main dependency
- [x] Testing of the existing workflow for logs (instead of only as a module)
- [x] Add log levels choice
Here is a look of the logger during a sample "run" of the CLI
That's one with the --verbose
option
@m-miedema @me-pic @smoia everything listed in this checklist is completed (+removal of Gooey), and should be ready to merge. Please review
One last change. In some test cases the test was checking if a UserWarning
was raised. This expects the warnings
module usage and not the loguru logger. The workaround I found was the following diff
--- with pytest.warns(UserWarning):
--- arr = io.load_physio(np.loadtxt(get_test_data_path('ECG.csv')))
+++ arr = io.load_physio(np.loadtxt(get_test_data_path("ECG.csv")))
+++ assert "WARNING" in caplog.text
where also a conftest.py
file had to be added, where the caplog fixture where the loguru messages would be redirected is instantiated (check here)
It just tests that a warning message was sent, similarly to the previous version where it just checked for a user defined warning.
The only thing that's different is that if multiple warnings are expected per unit test, this assertion is not enough. In 86adcf3 I added a "WARNING" occurence count, as deemed more appropriately in each specific test.
assert caplog.text.count("WARNING") == 1
I believe it's a sufficient warning assertion. Let me know your thoughts @smoia @m-miedema @me-pic (now all unit tests are behaving similarly to the master branch)
One last change. In some test cases the test was checking if a
UserWarning
was raised. This expects thewarnings
module usage and not the loguru logger. The workaround I found was the following diff--- with pytest.warns(UserWarning): --- arr = io.load_physio(np.loadtxt(get_test_data_path('ECG.csv'))) +++ arr = io.load_physio(np.loadtxt(get_test_data_path("ECG.csv"))) +++ assert "WARNING" in caplog.text
where also a
conftest.py
file had to be added, where the caplog fixture where the loguru messages would be redirected is instantiated (check here)It just tests that a warning message was sent, similarly to the previous version where it just checked for a user defined warning.
The only thing that's different is that if multiple warnings are expected per unit test, this assertion is not enough. In 86adcf3 I added a "WARNING" occurence count, as deemed more appropriately in each specific test.
assert caplog.text.count("WARNING") == 1
I believe it's a sufficient warning assertion. Let me know your thoughts @smoia @m-miedema @me-pic (now all unit tests are behaving similarly to the master branch)
This seems like a reasonable solution to me, but @smoia has more experience with how the tests were originally set up here!
@m-miedema we can discuss it sure! You could also elaborate here if you want. In general, the logger enabling is added for the following reasons:
- Most people using the module as a library, would not want the module-inherent logs to be mixed with their own, that's why by default it's disabled (see
__init__.py
addition). However this only includes our user defined logs, errors would be normally thrown - For the people that will use the CLI, the logger would be enabled by default, since that's the core functionality we would require it for.
- If the library-users would like to have the loguru logs enabled they can call the
enable_logger()
function, enabling it in the level they prefer.
Do you find a specific part confusing? Let me know your thoughts.
@m-miedema I added some extra functions to disable the logger and configure the log level. Then also the appropriate warnings and errors are added to point the users to the correct usage of the functions. Now if you create more than one instances you have a warning, and you are pointed to the correct way to change log level. Let me know if this works for you!
@m-miedema I added some extra functions to disable the logger and configure the log level. Then also the appropriate warnings and errors are added to point the users to the correct usage of the functions. Now if you create more than one instances you have a warning, and you are pointed to the correct way to change log level. Let me know if this works for you!
Looks great, thank you for adding these! Just waiting to hear back from @smoia to proceed with the merge.
:rocket: PR was released in 0.4.0
:rocket: