[ENH]: add execution time to read/write tracing

[c-gamble]

Description of changes

This PR introduces execution time tracing to read and write operations on collections. We introduce a request_execution_time_ns field to any tracing event whose request performs a read or write operation on a collection. These are bundled and emitted on the frontend.

TODO:

• Calculate request execution time
• Bundle execution time measurements on frontend to flush to S3 as floating point arrays

Test plan

• Tests pass locally with :
  - [x] pytest for python,
  - [x] yarn test for js
  - [x] cargo test for rust

Documentation Changes

N/A

[github-actions]

Reviewer Checklist

Please leverage this checklist to ensure your code review is thorough before approving

Testing, Bugs, Errors, Logs, Documentation

• Can you think of any use case in which the code does not behave as intended? Have they been tested?
• Can you think of any inputs or external events that could break the code? Is user input validated and safe? Have they been tested?
• If appropriate, are there adequate property based tests?
• If appropriate, are there adequate unit tests?
• Should any logging, debugging, tracing information be added or removed?
• Are error messages user-friendly?
• Have all documentation changes needed been made?
• Have all non-obvious changes been commented?

System Compatibility

• Are there any potential impacts on other parts of the system or backward compatibility?
• Does this change intersect with any items on our roadmap, and if so, is there a plan for fitting them together?

Quality

• Is this code of a unexpectedly high quality (Readability, Modularity, Intuitiveness)

[HammadB]

Hmm this feels a bit leaky to expose in all methods we call, I think we ought to think of a better abstraction/design here. Will think on this. cc @sanketkedia @Sicheng-Pan

[drewkim]

Can we use thread_local storage? https://doc.rust-lang.org/std/macro.thread_local.html

[HammadB]

This is an async runtime, so I doubt that works since tasks can move between threads. That also feels overly magic. I think we are just in need of some encapsulation or indirection.

[drewkim]

tokio::task_local? https://docs.rs/tokio_wasi/latest/tokio/macro.task_local.html https://docs.rs/axum/0.7.7/axum/#using-tokios-task_local-macro

Edit:

I think we are just in need of some encapsulation or indirection.

Makes sense

[c-gamble]

Additional context

[HammadB]

Aside - I suggest the use of instant for this sort of a task - https://users.rust-lang.org/t/why-is-std-instant-opaque/74786

[HammadB]

https://doc.rust-lang.org/std/time/struct.Instant.html

[c-gamble]

with the current implementation relying on passing the start time through the request object, we need whatever type we use to be serializable via utoipa. we can opt for chrono::DateTimechrono::Utc as we figure out a better long-term metering solution.

[HammadB]

One potential option is for service based frontend to accept a partially built MeterEvent, and add the subsequent data to it and submit it. We can follow the https://cliffle.com/blog/rust-typestate/ and have partial types. This is a bit verbose so I don't love it but its an option.

[HammadB]

Nice comment

[propel-code-bot]

Add Execution Time Tracing to Read/Write Operations

This PR introduces tracking of execution time for read and write operations in the Chroma database, adding a request_execution_time_ns field to relevant tracing MeterEvent variants. This field is propagated and emitted on the frontend, using chrono::DateTimechrono::Utc for timestamp tracking, with extensive plumbing to ensure all affected API requests include the request start timestamp. The changes span request/response data types, core logic in the Rust frontend implementation, and corresponding updates to Python bindings, testing infrastructure, and dependencies.

Key Changes:
• Introduced request_execution_time_ns (optional u128, serialized as hex) on CollectionFork, CollectionRead, and CollectionWrite tracing events.
• Tracked request start time (received_at_timestamp; chrono::DateTime) in all major API request structs and methods.
• Calculated execution duration at end of request handling (using Utc::now - request_received_at_timestamp) and placed result in MeterEvent.
• Propagated and required received_at_timestamp throughout Rust API layer, Rust-Python bindings, axum (REST) server handlers, and test helpers.
• Added a utility module for (de)serializing optional u128 as hex.
• Upgraded chrono and serde dependencies, updated struct and constructor signatures accordingly.
• Enhanced tests for new fields and proper serialization logic.

Affected Areas:
• rust/frontend/src/impls/service_based_frontend.rs
• rust/types/src/api_types.rs
• rust/types/src/u128.rs
• rust/tracing/src/meter_event.rs
• rust/python_bindings/src/bindings.rs
• rust/frontend/src/server.rs
• API request/response object definitions and tests
• Cargo.toml and dependencies
• Python and Rust test harnesses

Potential Impact:

Functionality: Execution time for read/write operations is now traceable on a per-request basis and included in MeterEvent telemetry, allowing for latency monitoring and eventual dashboards.

Performance: Negligible runtime overhead from capturing and storing request timestamps/durations per operation.

Security: No direct security impact; only tracking timing information.

Scalability: Minimal impact, but adds small metadata to every traced request. No major scalability concern.

Review Focus:
• Correctness of request timestamp propagation across all layers and interfaces.
• Accuracy and robustness of execution time calculation.
• Proper handling and serialization of optional u128 fields.
• Backward compatibility for older clients or omitted fields.
• Potential design improvements to avoid plumbing timestamps through all API layers.

Testing Needed

• Verify that all read/write operations (Add, Update, Upsert, Delete, Fork, Query, Get, Count) correctly record request_execution_time_ns in the tracing event.
• Ensure request start timestamp is accurately propagated from entrypoint to handler.
• Test new serde logic for optional u128 serialization/deserialization.
• Check that existing and new tests (including proptests) pass.
• Validate proper functioning across both REST and Python interfaces.

Code Quality Assessment

rust/python_bindings/src/bindings.rs: Python interface updated to pass through current Utc::now, with related plumbing.

rust/types/src/u128.rs: New module is clear, tested, and follows Rust/Serde conventions for (de)serializing optional u128 values as hex.

rust/tracing/src/meter_event.rs: Expanded for new field, correct serialization attributes, and new tests for serialization cases.

rust/frontend/src/impls/service_based_frontend.rs: Touches many methods to accept and forward timestamps; comments and reviewer feedback suggest design concerns but implementation is methodical.

rust/types/src/api_types.rs: All major API requests augmented for received_at_timestamp; constructors and validation extended accordingly.

Best Practices

Observability:
• Operation telemetry for latency tracing
• Structured event logging

Serialization:
• Interop via custom serde logic for optional u128+hex

Testing:
• Added/updated tests for new data flows and serialization correctness

Dependency Management:
• Synchronized chrono and serde versions across crates

Potential Issues

• Current design requires explicit timestamp argument/field in many places, which can be error-prone or brittle long-term.
• Some reviewers expressed concern about leaking internal timing details into public method signatures.
• Async context (lack of thread/task-local storage use) may pose future maintainability or ergonomic challenges.
• If a client fails to provide a timestamp, potential for incorrect execution time measurements.
• No fallback if system clock is incorrect or skewed (edge case).

This summary was automatically generated by @propel-code-bot