-
-
Notifications
You must be signed in to change notification settings - Fork 18
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
register teal.logger handlers; replace log_info with message #1010
Conversation
@pawelru is this ready? I think it is a nice to have |
I think it's in very odd state. It's ready to be reviewed (+ core functionality) but probably not to be merged. This will block the tmc release until release of teal.reporter which is something we don't want |
Signed-off-by: Pawel Rucki <[email protected]>
Unit Tests Summary 1 files 33 suites 2s ⏱️ Results for commit 3dc9c1b. ♻️ This comment has been updated with latest results. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Cpasiba!
close insightsengineering/coredev-tasks#502 #69 I tried to use `logger::log_messages()` (and similar functions for warnings and errors) but I have encounter following problems: - this is logging into the global logger namespace whereas we want particular (package) namespace instead - created an issue - I cloned logger locally and fixed / enhanced the above but then I realized that the (global) message / warning / stop calls from the outside of a package will also log to that package logger namespace. In other words, these are _global_ handlers for all the warnings and not only warnings created inside `teal` e.g. ``` r$> warning(1) [WARN] 2024-01-26 15:58:17.0061 pid:83248 token:[] teal 1 Warning message: 1 ``` Therefore I have decided to implement own register handlers mechanism. I initially started doing this separately inside each package but then I realised that it's not so DRY and decided to extend core `teal.logger` functionality. This is not a reprex as I modified `teal` and `teal.slice` namespaces in a following way: - added `register_handlers(<pkg>)` in both packages - For debugging: added following definitions: - `teal.slice`: - `teal_s_message` calling `message()` - `teal_s_warning` calling `warning()` - `teal_s_stop` calling `stop()` - in `teal`: - `teal_message` calling `message()` - `teal_warning` calling `warning()` - `teal_stop` calling `stop()` - `teal_message_nested` calling `teal_s_message()` (so as to simulate `teal` calling `teal.slice`) - `teal_warning_nested` calling `teal_s_warning()` - `teal_stop_nested` calling `teal_s_stop()` The outcome: ``` r$> devtools::load_all("teal.logger") r$> devtools::load_all("teal.slice") r$> devtools::load_all("teal") r$> message(1) 1 r$> teal_message(1) [INFO] 2024-01-26 15:57:40.8901 pid:83248 token:[] teal 1 1 r$> teal_s_message(1) [INFO] 2024-01-26 15:57:42.1464 pid:83248 token:[] teal.slice 1 1 r$> teal_message_nested(1) [INFO] 2024-01-26 15:57:50.9231 pid:83248 token:[] teal 1 [INFO] 2024-01-26 15:57:50.9257 pid:83248 token:[] teal.slice 1 1 r$> warning(2) Warning message: 2 r$> teal_s_warning(2) [WARN] 2024-01-26 15:58:17.0061 pid:83248 token:[] teal.slice In ‘teal_s_warning(2)’: 2 Warning message: In teal_s_warning(2) : 2 r$> teal_warning(2) [WARN] 2024-01-26 15:58:18.4165 pid:83248 token:[] teal In ‘teal_warning(2)’: 2 Warning message: In teal_warning(2) : 2 r$> teal_warning_nested(2) [WARN] 2024-01-26 15:58:20.8666 pid:83248 token:[] teal In ‘teal.slice:::teal_s_warning(message)’: 2 [WARN] 2024-01-26 15:58:20.8685 pid:83248 token:[] teal.slice In ‘teal.slice:::teal_s_warning(message)’: 2 Warning message: In teal.slice:::teal_s_warning(message) : 2 r$> stop(3) Error: 3 r$> teal_s_stop(3) [ERROR] 2024-01-26 15:58:32.9558 pid:83248 token:[] teal.slice In ‘teal_s_stop(3)’: 3 Error in teal_s_stop(3) : 3 r$> teal_stop(3) [ERROR] 2024-01-26 15:58:33.5246 pid:83248 token:[] teal In ‘teal_stop(3)’: 3 Error in teal_stop(3) : 3 r$> teal_stop_nested(3) [ERROR] 2024-01-26 15:58:34.0213 pid:83248 token:[] teal In ‘teal.slice:::teal_s_stop(message)’: 3 [ERROR] 2024-01-26 15:58:34.0226 pid:83248 token:[] teal.slice In ‘teal.slice:::teal_s_stop(message)’: 3 Error in teal.slice:::teal_s_stop(message) : 3 ``` Interpretation (where "m/w/s" stands for "message / warning / stop"): - global m/w/s is not impacted - we only capture m/w/s called from inside the package - capturing m/w/s in the appropriate logger namespace - see it as a part of logger produced string - second last part - the case of nested calls looks odd at the very first glance but I think it's correct. Each (package) logger instance might have its own log threshold, appender function, layout etc. It's expected to have duplicated logs for each of the registered package namespace found on the stack of calls. I'm interested in hearing your thoughts on this PRs: - [ ] insightsengineering/teal#1081 - [ ] insightsengineering/teal.goshawk#258 - [ ] insightsengineering/teal.modules.clinical#1010 - [ ] insightsengineering/teal.modules.general#628 - [ ] insightsengineering/teal.modules.hermes#354 - [ ] insightsengineering/teal.osprey#252 - [ ] insightsengineering/teal.slice#551 - [ ] insightsengineering/teal.transform#175 (I'll keep them as draft as this is conflicting with release plans because teal.logger would have to be released first) TODO: tests - however I'm not yet sure how to make them "clean" --------- Signed-off-by: Pawel Rucki <[email protected]> Co-authored-by: Dawid Kałędkowski <[email protected]>
close https://github.com/insightsengineering/coredev-tasks/issues/502
test with insightsengineering/teal.logger#73
As a bonus, we can safely move
logger
to suggests (it's still used in tests)