iceberg-rust icon indicating copy to clipboard operation
iceberg-rust copied to clipboard

Investigation about tracing, logging, and metrics support.

Open liurenjie1024 opened this issue 1 year ago • 12 comments

As a library for production usage, it would be useful to add logging, metrics, and tracing support. We need to do some investigation about to fit into rust ecosystem as much as possible.

liurenjie1024 avatar Jul 26 '24 09:07 liurenjie1024

I will suggestion the following set:


Why not tracing?

Tracing is widely used, but it often confuses the scope of logging and tracing.

From a tracing perspective, it's 100 times slower than fastrace.

Meanwhile, log offers the most compatible solution for all logging systems, making integration easier for users.

Why not prometheus?

prometheus project maintained by tikv community is almost dead.

Why not metrics?

It makes sense to introduce an abstraction based on metrics tailored to my own usage. However, its abstraction does not effectively support prometheus, which is the most widely used metrics collector.

I suggest we first integrate directly with Prometheus and consider metrics, while also accommodating requests for support of other metrics tools like tcp.

Xuanwo avatar Jul 26 '24 09:07 Xuanwo

Personally I'd support tracing crate over logging. Adoption of tracing has supplanted that of logging over the past few years. It is more capable and flexible than logging. I disagree with the sentiment that it confuses things.

sdd avatar Jul 26 '24 19:07 sdd

Adoption of tracing has supplanted that of logging over the past few years.

Users who rely on tracing can still integrate with our log, as tracing has native integration. However, if we adopt tracing, then log users will not be able to integrate with us. Therefore, I believe libraries like Iceberg should use log instead of tracing. Nonetheless, I'm open to using tracing_subscriber in our tests for a better user experience.

Here is a decision matrix:

Does it works? iceberg use log iceberg use tracing
user use env_logger (log ecosystem) YES NO
user use tracing_subscriber(tracing ecosystem) YES YES

Xuanwo avatar Jul 27 '24 05:07 Xuanwo

Hi, @sdd

It is more capable and flexible than logging.

Could you elaborate on this? Previously for logging capability I thought tracing crate is better since it provides structural logging, but log also provides structural logging now.

As with using tracing + logging backends, there is tracing-log, but it seems it's not actively maintained.

I'm trying to summarize the proposed approaches here:

log + fastrace

Pros:

  • Each crate fouces on its own functionality only, that means they have most widely supported ecosystem, and maybe easier to enable logging and tracing separately?
  • fastrace reports that it's much faster than tracing.

Cons:

  • tracing seems to have better ecosystem if you look at their main page.
  • It seems that fastrace is less popular than tracing, that means it maybe more difficult to integrate with other libraries? For example if someone wants to use iceberg-rust in an application in h2, which relies on tracing library, that means the user needs to setup two collectors/subscribers?

tracing only

Pros:

  • Most widely used tracing library in rust with best integrations.

Cons:

  • It's mixing logging with tracing. If we use tracing for logging, our logging compability will not be compatible with logger system.
  • It's reported to be slower than fastrace.

So how about we use log + tracing? We stick to the rule that using tracing library for tracing only, and use log for logging?

liurenjie1024 avatar Jul 28 '24 15:07 liurenjie1024

Hi all,

I agree with @sdd and suggest to stick with tracing. It is the default choice for logging in async applications and has the most wide-spread adoption.

Regarding performance arguments, I doubt that this matters in any real world benchmark of this crate, any tracing incurred overhead will be dwarfed by the network latencies of whatever storage cloud service serves the data files / roundtrips to DB catalog / API calls to a Rest catalog. I'm strongly in favor with sticking with a tried and tested implementation and put some real world benchmarks in place and only if those show tracing to be a bottleneck consider choosing a less active alternative.

I also do not agree with the sentiment that it is a problem to address tracing & logging in the same crate. It rather provides very useful debugging utilities, e.g. when used in a server, some middleware can create a span containing a request id, now every (tracing-)log statement within that span will have the request id attached to it so your favorite log aggregator can filter by this request id to get all logs pertaining to it which is incredibly helpful when dealing with production issues.

Regarding metrics, I'm not sure I understand the issue, there exists https://crates.io/crates/metrics-prometheus which provides integration of prometheus with metrics.rs.

twuebi avatar Jul 29 '24 08:07 twuebi

Hey guys, some thoughts from my side:

  • I don't think performance matters much - we are talking nanoseconds while roundtrips to S3 and catalogs are Milliseconds. Thus, the wider adoption is a clear plus for me for tracing.
  • We are an io-heavy crate - lots of roundtrips via OpenDAL to Object Stores, Catalogs and more. IMO we would benefit alot from the tracing features over plain logging. It would enable us to consistently track operations across all affected systems - including forwarding of trace-ids to them. Iceberg-Rust is one component in an inherently distributed system that we call a Lakehouse. Distributed systems can best be monitored as a whole if traces are used everywhere along the way.

c-thiel avatar Jul 30 '24 09:07 c-thiel

Thank you all for joining the discussion. It seems most people prefer using tracing for trace and log. I'm willing to accept this since it's more important for us to move forward.

The left part from my side is metrics: What do you think about prometheus_client and metrics?


Context from opendal.

OpenDAL supports ALL. Regardless of the library chosen, we simply need to enable the corresponding layer for it.

Name Depends Description
DtraceLayer probe Support User Statically-Defined Tracing(aka USDT) on Linux
LoggingLayer log Add log for every operations.
MetricsLayer metrics Add metrics for every operations.
FastraceLayer fastrace Add fastrace for every operations.
OtelTraceLayer opentelemetry::trace Add opentelemetry::trace for every operations.
PrometheusClientLayer prometheus_client Add prometheus metrics for every operations.
PrometheusLayer prometheus Add prometheus metrics for every operations.
TracingLayer tracing Add tracing for every operations.

Xuanwo avatar Jul 30 '24 09:07 Xuanwo

Some additional context. Renjie mentioned:

Cons: It's mixing logging with tracing. If we use tracing for logging, our logging compability will not be compatible with logger system.

This is not quite right. You can use the tracing_log crate to redirect any other crates logs that went to log to tracing:

use tracing_log::LogTracer;

// redirects all output sent to log:* to their tracing::* equivalent
LogTracer::init().expect("Failed to set logger");

Regarding metrics, my preference would be either metrics or opentelemetry. Both are vendor-agnostic with pluggable exporters. My first choice would be opentelemetry as it seems to have better cross-language recognition and a bit more active / vibrant community (I'm basing this on github stars, watchers, number of contributors and commit / merge frequency)

sdd avatar Jul 30 '24 20:07 sdd

It sounds like tracing is the preferred option for tracing and logging. I'm happy to raise a PR to add this if we are all in agreement.

Regarding telemetry, does anyone have objections to the choice of opentelemetry?

sdd avatar Jul 31 '24 21:07 sdd

It sounds like tracing is the preferred option for tracing and logging. I'm happy to raise a PR to add this if we are all in agreement.

I'm fine with this. Also cc @liurenjie1024 for ideas.

Regarding telemetry, does anyone have objections to the choice of opentelemetry?

opentelemetry's metrics support is currently in the Alpha stage. I believe most people primarily use it for trace. See: https://opentelemetry.io/docs/languages/rust/

I will support to use metrics instead if we don't want to depends on lib like prometheus_client directly.

Xuanwo avatar Aug 01 '24 05:08 Xuanwo

It sounds like tracing is the preferred option for tracing and logging. I'm happy to raise a PR to add this if we are all in agreement.

+1.

I will support to use metrics instead if we don't want to depends on lib like prometheus_client directly.

+1. I would also prefer to use metrics since opentelemetry is in too early stage.

liurenjie1024 avatar Aug 02 '24 01:08 liurenjie1024

Some additional context. Renjie mentioned:

Cons: It's mixing logging with tracing. If we use tracing for logging, our logging compability will not be compatible with logger system.

This is not quite right. You can use the tracing_log crate to redirect any other crates logs that went to log to tracing:

use tracing_log::LogTracer;

// redirects all output sent to log:* to their tracing::* equivalent
LogTracer::init().expect("Failed to set logger");

Regarding metrics, my preference would be either metrics or opentelemetry. Both are vendor-agnostic with pluggable exporters. My first choice would be opentelemetry as it seems to have better cross-language recognition and a bit more active / vibrant community (I'm basing this on github stars, watchers, number of contributors and commit / merge frequency)

I have a question: the LogTracer in tracing_log is used to convert the log record into a trace event. Does this mean that if the user uses log originally and after they introduce iceberg-rust, they have two choices:

  1. maintain trace and log separately
  2. use trace and redirect all original log records into trace events.

For users, is it a more ideal behavior to redirect the trace to the original log? 🤔

ZENOTME avatar Aug 04 '24 11:08 ZENOTME

There is a post for why I prefer fastrace + log: https://fast.github.io/blog/fastrace-a-modern-approach-to-distributed-tracing-in-rust/

Xuanwo avatar Mar 24 '25 04:03 Xuanwo

I've looked into fastrace a bit more after our conversations about it yesterday and I must admit I have serious reservations about it.

The benchmarks as reported by fastrace have been pointed out by tracing maintainers as being somewhat misleading as they are not comparing like-for-like. Whilst fastrace does still come out faster, it is nowhere near the difference claimed when a like-for-like comparison is made.

Reference: https://www.reddit.com/r/rust/comments/1jh2fzg/fastrace_a_modern_approach_to_distributed_tracing/

In the blog post, the author makes claims about ecosystem fragmentation. I don't see how this is solved by introducing another tracing library. tracing is able to integrate with log already simply by enabling the log feature of tracing within our library. This is something that would be straightforward for consumers to do, and is also pretty common within the ecosystem already.

So, someone who already has an application that is using tracing for tracing and logging is able to record logs from libraries that use tracing or log, and emit logs to either tracing or log collectors. But, they would have no recourse if they wanted to capture logs from a library using fastrace because there is no similar means of exporting fastrace logs / traces to tracing. This seems to make fragmentation worse, not better.

The blog post claims that:

With tokio-rs/tracing, there’s no clean way to have tracing zero-cost disabled. This makes library authors reluctant to add instrumentation to performance-sensitive code paths.

But it is trivial to do this in tracing too: https://docs.rs/tracing/latest/tracing/level_filters/index.html#compile-time-filters

On context propagation, the blog post also claims that:

tokio-rs/tracing leaves this largely as an exercise for the developer.

The blogpost seems to be deliberately misleading on this. It is pretty trivial to do this in the tracing ecosystem. In a real-life service you can do this trivially in one line of code by using libraries like tonic-tracing-opentelemetry for gRPC services in Tonic or axum-tracing-opentelemetry for HTTP services in Axum. In fact this is the exact same approach that fastrace has also used, with the fastrace-tonic and fastrace-axum crates being separate.

On the whole, the only claim in the blog that really holds up to scrutiny is that fastrace performs better. But even that has been exaggerated, can be mitigated, and in my real-world experience with using tracing with iceberg-rust already, is not significant enough to notice.

Conversely, tracing has:

  • A much wider ecosystem (see https://docs.rs/tracing/latest/tracing/#related-crates)
  • much greater configurability
  • 10x as many GitHub stars
  • 50x as many daily downloads (it gets downloaded more times in one day than fastrace has in its entire history).

sdd avatar Mar 28 '25 09:03 sdd

@ZENOTME said:

For users, is it a more ideal behavior to redirect the trace to the original log? 🤔

Yes, and this is simple to do with tracing by just enabling tracing's log feature and not using a tracing-subscriber (or even logging to both log and a tracing-subscriber by setting the log-always feature).

See https://docs.rs/tracing/0.1.41/tracing/#crate-feature-flags

sdd avatar Mar 28 '25 09:03 sdd

Hi @sdd, I had a discussion with the fastrace developers and found that tracing is unable to collect the spans generated by fastrace.

Therefore, I agree that we should use tracing instead of log and fastrace.

Xuanwo avatar Mar 28 '25 09:03 Xuanwo

So our final decision will be to use tracing along with metrics-rs.

Xuanwo avatar Mar 28 '25 09:03 Xuanwo

This sounds good to me! I'm happy to pick this work up, as well as putting together examples and documentation of how to use them in practice. It will be a massive gain for all of us to finally have these pieces in place 😊

sdd avatar Mar 28 '25 11:03 sdd

Thanks everyone for the discussion, glad to see that we reached consensus on this part!

liurenjie1024 avatar Mar 28 '25 13:03 liurenjie1024

Hi All - I've been distracted with other things for a while but I've recently found time to pick this back up and have good progress so far. See the description on https://github.com/apache/iceberg-rust/pull/1502 for some details.

Some open questions / tasks:

  • Feedback on the granularity of the traces I've implemented at different log levels appreciated. I've been using similar levels of tracing in production now on my iceberg fork for a few months and it has proved very useful, and I've taken the lessons I've learned from that process to feed in to this greenfield implementation.
  • A documented naming scheme for trace spans would be good to have. Ideally one that aligns with cross-language iceberg implementations
  • Ditto for naming tracing events
  • Ditto for metrics for Prometheus etc
  • Documented guidelines / policy for what / where to instrument with spans / logs / metrics and at what level (ie info/debug/trace)
  • My PR contains changes necessary to the integration test setup as well as the instrumentation itself. I'd appreciate feedback / critique on the approach. It might make sense to split that part out if there is any controversy
  • Where is a good location to add documentation / examples for consumers of the library for how to integrate iceberg traces/metrics with common observability stacks

One final observation. There's a trade-off to be had - at one end of the spectrum, the tracing / metrics instrumentation is as light-touch on the codebase as possible, with the implementation prioritising simplicity and clarity of the primary business logic at the expense of less cohesive / coherent traces within the observability tooling. At the other end of this spectrum, the control flow and readability of the core logic is completely disregarded in order to generate the most accurate and readable traces.

I've trodden a path closer towards the latter with this PR. It is not easy in Rust to get traces that are the most useable to consumers when you are working with streams of streams with multiple async stages. Getting the traces to look right was my goal with this PR and the cost of that is some loss of readability. My rationale is that I'd estimate that many more people will look at traces than will read the codebase. But as ever this is a discussion point.

sdd avatar Jul 18 '25 18:07 sdd