[POC|PM-28135] Add crypto tracing logs #555
Conversation
|
Great job! No new security vulnerabilities introduced in this pull request |
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #555 +/- ##
==========================================
- Coverage 79.71% 79.53% -0.18%
==========================================
Files 300 300
Lines 32238 32068 -170
==========================================
- Hits 25697 25505 -192
- Misses 6541 6563 +22 ☔ View full report in Codecov by Sentry. 🚀 New features to boost your workflow:
|
quexten
changed the title
|
Note: This has some overlap with #550, as this also enables tracing. The linked PR enables tracing and removes log. |
dani-garcia
left a comment
dani-garcia
left a comment
There was a problem hiding this comment.
Looks pretty reasonable to me, just got some small comments.
|
Do we have any concerns about runtime performance? I think tracing negatively impacts performance but they have ways to indicate some should be compiled out, https://docs.rs/tracing/latest/tracing/level_filters/index.html#compile-time-filters. (I suspect tracing performance to be a drop in the bucket for the crypto operations but I think this is a worthwhile discussion to have) |
Co-authored-by: Daniel García <[email protected]>
|
Claude finished @quexten's task —— View job Code Review CompleteTodo List
Summary of Changes Since Last ReviewThe PR has evolved significantly with 25 commits. Recent changes include:
Critical IssuesFinding 1: The WASM initialization code can panic on subsequent calls to In tracing_subscriber::registry().with(fmt_layer).init();Recommendation: Use if let Err(_) = tracing_subscriber::registry().with(fmt_layer).try_init() {
// Already initialized, which is fine
}Good Practices Observed
Suggested ImprovementsFinding 2: Consider explicit `attributes` feature declarationIn tracing = { version = "0.1.41", features = ["release_max_level_info", "attributes"] }This is a minor improvement for defensive coding. Finding 3: The span creation pattern could be simplifiedIn let _span_guard = tracing::info_span!("...", ...).entered();However, this creates two variable bindings. The let _span = tracing::info_span!("...", ...).entered();This was actually suggested by dani-garcia in a previous review comment and appears to have been partially addressed but not in all locations. Finding 4: Add TODO comment for temporary dual-logging systemIn // TODO(PM-28135): Remove old logging system once tracing migration is complete
let log_level = convert_level(log_level.unwrap_or(LogLevel::Info));
if let Err(_e) = console_log::init_with_level(log_level) {
set_max_level(log_level.to_level_filter())
}Previous Review ItemsResolved:
Partially Resolved:
Still Outstanding:
Test CoverageCodecov reports 30% patch coverage with 7 lines missing in the tracing initialization code. Given that this is initialization and logging infrastructure, this is acceptable. The core crypto paths being traced are well-tested through existing tests. Security Considerations
Action Items for Author
Overall AssessmentThis is a solid implementation of tracing infrastructure for the crypto paths. The placement of tracing spans is appropriate and follows best practices. The main concern is the WASM initialization panic risk, which should be addressed before merging. The PR achieves its stated objective of enabling tracing without removing the old logging system, setting the stage for future migration work. |
![claude[bot]](https://avatars.githubusercontent.com/in/1236702?s=60&v=4){kind=small}
|
@Hinton My biggest concern would be if tracing somehow is blocking with respect to the subscribers, and we would log a lot (possibly having to go to JS every time via the hooking to console it uses), though a quick check suggests that it just appends to a buffer that then gets flushed, and actual logs should not be that frequent with the current implementation. Is there specific things that you'd like to see measured here? Vault unlock times for large vaults? Actual logs should only be emitted for errors / rare info events, but obviously the context is still stored into a buffer somewhere. |
|
@quexten Comparing calling decrypt 100'000 times with tracing to 100'000 without in a test maybe? I think it's a drop in the bucket. But I feel like it's probably not necessary to be honest. I do think it's good to decide if we want any of the |
|
@Hinton Okay, I've not further benchmarked it since I agree that it's most likely negligible. I've set the max log level to In case we do want logging in an operation that gets called millions of times, we should consider using debug/trace to have it compiled out in release. |
🔍 SDK Breaking Change Detection ResultsSDK Version:
Breaking change detection completed. View SDK workflow |
🎟️ Tracking
https://bitwarden.atlassian.net/browse/PM-28135
📔 Objective
Enables
tracing, but does not yet remove the old logging (follow-up). It adds tracing to the most important crypto paths. Follow-up tickets may add more tracing.Example log output:
⏰ Reminders before review
team
🦮 Reviewer guidelines
:+1:) or similar for great changes:memo:) or ℹ️ (:information_source:) for notes or general info:question:) for questions:thinking:) or 💭 (:thought_balloon:) for more open inquiry that's not quite a confirmedissue and could potentially benefit from discussion
:art:) for suggestions / improvements:x:) or:warning:) for more significant problems or concerns needing attention:seedling:) or ♻️ (:recycle:) for future improvements or indications of technical debt:pick:) for minor or nitpick changes