davidbarsky / tracing-tree

Apache License 2.0
123 stars 31 forks source link

Format and print time at which event has occurred #56

Closed TmLev closed 1 year ago

TmLev commented 1 year ago

As discussed in #49, new FormatTime trait is introduced and implemented for a few basic scenarios:

Here's an example of how it looks with UtcDateTime:

Logs from `examples/basic.rs` ```logs 1:main┐basic::hierarchical-example version=0.1 1:main├┐basic::hierarchical-example version=0.1 1:main│└┐basic::server host="localhost", port=8080 1:main│ ├─2023-03-31 10:27:25.122113 0ms INFO basic starting 1:main│ ├─2023-03-31 10:27:25.427151 305ms INFO basic listening 1:main│ ├┐basic::server host="localhost", port=8080 1:main│ │└┐basic::conn peer_addr="82.9.9.9", port=42381 1:main│ │ ├─2023-03-31 10:27:25.427267 0ms DEBUG basic connected 1:main│ │ ├─2023-03-31 10:27:25.728098 300ms DEBUG basic message received, length=2 1:main│ │┌┘basic::conn peer_addr="82.9.9.9", port=42381 1:main│ ├┘basic::server host="localhost", port=8080 1:main│ ├┐basic::server host="localhost", port=8080 1:main│ │└┐basic::conn peer_addr="8.8.8.8", port=18230 1:main│ │ ├─2023-03-31 10:27:26.0303 302ms DEBUG basic connected 1:main│ │┌┘basic::conn peer_addr="8.8.8.8", port=18230 1:main│ ├┘basic::server host="localhost", port=8080 1:main│ ├┐basic::server host="localhost", port=8080 1:main│ │└┐basic::foomp 42 <- format string, normal_var=43 1:main│ │ ├─2023-03-31 10:27:26.030431 0ms ERROR basic hello 1:main│ │┌┘basic::foomp 42 <- format string, normal_var=43 1:main│ ├┘basic::server host="localhost", port=8080 1:main│ ├┐basic::server host="localhost", port=8080 1:main│ │└┐basic::conn peer_addr="82.9.9.9", port=42381 1:main│ │ ├─2023-03-31 10:27:26.030491 0ms WARN basic weak encryption requested, algo="xor" 1:main│ │ ├─2023-03-31 10:27:26.331355 300ms DEBUG basic response sent, length=8 1:main│ │ ├─2023-03-31 10:27:26.331516 301ms DEBUG basic disconnected 1:main│ │┌┘basic::conn peer_addr="82.9.9.9", port=42381 1:main│ ├┘basic::server host="localhost", port=8080 1:main│ ├┐basic::server host="localhost", port=8080 1:main│ │└┐basic::conn peer_addr="8.8.8.8", port=18230 1:main│ │ ├─2023-03-31 10:27:26.331738 0ms DEBUG basic message received, length=5 1:main│ │ ├─2023-03-31 10:27:26.633213 301ms DEBUG basic response sent, length=8 1:main│ │ ├─2023-03-31 10:27:26.633372 301ms DEBUG basic disconnected 1:main│ │┌┘basic::conn peer_addr="8.8.8.8", port=18230 1:main│ ├┘basic::server host="localhost", port=8080 1:main│ ├─2023-03-31 10:27:26.633815 1511ms WARN basic internal error 1:main│ ├─2023-03-31 10:27:26.633901 1511ms ERROR basic this is a log message 1:main│ ├─2023-03-31 10:27:26.633946 1511ms INFO basic exit 1:main│┌┘basic::server host="localhost", port=8080 1:main├┘basic::hierarchical-example version=0.1 1:main┘basic::hierarchical-example version=0.1 ```

Closes #48. Supersedes #49.

TmLev commented 1 year ago

@ten3roberts can you try this PR out and share your feedback?

ten3roberts commented 1 year ago

Looks nice and works on my end.

Would it be possible to add the UtcTime struct (maybe feature gate it) which allows a bit shorted and succint timestamps compared to the OffsetDateTime in addition for wasm32 support.

Perhaps the Uptime is a bit too precise

Uptime Screenshot 2023-03-30 at 11 28 10

OffsetDateTime Screenshot 2023-03-30 at 11 28 37

Perhaps some padding between the timestamp and span duration, as they are now back to back.

Thanks for your work

TmLev commented 1 year ago
TmLev commented 1 year ago

@ten3roberts can you please tell me more about wasm32 support? Which part of this PR prevents wasm32 from being supported?

ten3roberts commented 1 year ago

Wow, looks much better

On wasm32-unknown-unknown Instant::now is not available and panics.

The time and chrono crates Utc and datetime can bind to js and the js Date api.

tracing-web mentions this in their readme

https://github.com/WorldSEnder/tracing-web#overview

TmLev commented 1 year ago

So what would you like me to do? Make a feature flag in tracing_tree for enabling time's wasm-bindgen feature?

ten3roberts commented 1 year ago

No, simply depending on time is enough, as the feature resolver will unify the wasm-bindgen feature which you add in the user crate

TmLev commented 1 year ago

Okay, got you.

@davidbarsky do you have time to review this PR?

davidbarsky commented 1 year ago

Sorry for the delay in looking at this: I haven't been able to review it depth because my employer is doing layoffs this week and I wanted to get some of the things I was working on done and released.

I'll give this a proper review in an hour.

oli-obk commented 1 year ago

I've been thinking about how to test this. A test could use a dummy FormatTime impl that uses interior mutability to increment the time by a fixed amount every time format_time is called. Please add a test like this so we have some minimal regression testing for this scheme.

TmLev commented 1 year ago

Made a test with an atomic counter which gets incremented each time its FormatTime implementation is supposed to be called. Is that what you had in mind?

P.S. GitHub is lagging hard right now, for some reason it doesn't show the latest commit. P.S.S. Everything works now.

oli-obk commented 1 year ago

Is that what you had in mind?

No, but your test is better than the one I had in mind 😆

gonna let CI run its course and then merge it

TmLev commented 1 year ago

Looks like CI is done?..

TmLev commented 1 year ago

Can I ask you to publish a new release with this PR?

oli-obk commented 1 year ago

We're figuring out permissions and stuff. May take a bit with back and forth across a large timezone gap.

oli-obk commented 1 year ago

A new version with this change has been published