feat: extend performance API with explicit timings (#1093)

* Extended API to allow explicit timings

* Add tests for timestamped API functions

* re-add todos and comments that went missing in refactoring

* update changelog

* update docstrings for new API

* apply refactoring suggestion from code review

* change assert_timestamp to be more accurate

* cleanup unnecessary includes

Author: JoshuaMoelans

CHANGELOG.md

@@ -4,6 +4,7 @@
 
 **Features**:
 - Add SOCKS5 proxy support for macOS and Linux. ([#1063](https://github.com/getsentry/sentry-native/pull/1063))
+- Extend performance API with explicit timings ([#1093](https://github.com/getsentry/sentry-native/pull/1093))
 
 ## 0.7.15
 

include/sentry.h

@@ -1736,6 +1736,16 @@ SENTRY_EXPERIMENTAL_API void sentry_transaction_context_update_from_header_n(
  */
 SENTRY_EXPERIMENTAL_API sentry_transaction_t *sentry_transaction_start(
     sentry_transaction_context_t *tx_cxt, sentry_value_t sampling_ctx);
+/**
+ * Also starts a transaction like the regular `sentry_transaction_start`
+ * function, but has an additional timestamp parameter to let the user provide
+ * explicit timings.
+ *
+ * The timestamp should be provided in microseconds since the Unix epoch.
+ */
+SENTRY_EXPERIMENTAL_API sentry_transaction_t *sentry_transaction_start_ts(
+    sentry_transaction_context_t *tx_cxt, sentry_value_t sampling_ctx,
+    uint64_t timestamp);
 
 /**
  * Finishes and sends a Transaction to sentry. The event ID of the Transaction
@@ -1748,6 +1758,15 @@ SENTRY_EXPERIMENTAL_API sentry_transaction_t *sentry_transaction_start(
  */
 SENTRY_EXPERIMENTAL_API sentry_uuid_t sentry_transaction_finish(
     sentry_transaction_t *tx);
+/**
+ * Also finishes a transaction like the regular `sentry_transaction_finish`
+ * function, but has an additional timestamp parameter to let the user provide
+ * explicit timings.
+ *
+ * The timestamp should be provided in microseconds since the Unix epoch.
+ */
+SENTRY_EXPERIMENTAL_API sentry_uuid_t sentry_transaction_finish_ts(
+    sentry_transaction_t *tx, uint64_t timestamp);
 
 /**
  * Sets the Transaction so any Events sent while the Transaction
@@ -1816,6 +1835,19 @@ SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_transaction_start_child(
 SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_transaction_start_child_n(
     sentry_transaction_t *parent, const char *operation, size_t operation_len,
     const char *description, size_t description_len);
+/**
+ * Also starts a span like the regular `sentry_transaction_start_child_ts`
+ * functions, but has an additional timestamp parameter to let the user provide
+ * explicit timings.
+ *
+ * The timestamp should be provided in microseconds since the Unix epoch.
+ */
+SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_transaction_start_child_ts(
+    sentry_transaction_t *parent, const char *operation,
+    const char *description, uint64_t timestamp);
+SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_transaction_start_child_ts_n(
+    sentry_transaction_t *parent, const char *operation, size_t operation_len,
+    const char *description, size_t description_len, uint64_t timestamp);
 
 /**
  * Starts a new Span.
@@ -1852,6 +1884,19 @@ SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_span_start_child(
 SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_span_start_child_n(
     sentry_span_t *parent, const char *operation, size_t operation_len,
     const char *description, size_t description_len);
+/**
+ * Also starts a span like the regular `sentry_span_start_child_ts` functions,
+ * but has an additional timestamp parameter to let the user provide explicit
+ * timings.
+ *
+ * The timestamp should be provided in microseconds since the Unix epoch.
+ */
+SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_span_start_child_ts(
+    sentry_span_t *parent, const char *operation, const char *description,
+    uint64_t timestamp);
+SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_span_start_child_ts_n(
+    sentry_span_t *parent, const char *operation, size_t operation_len,
+    const char *description, size_t description_len, uint64_t timestamp);
 
 /**
  * Finishes a Span.
@@ -1864,6 +1909,14 @@ SENTRY_EXPERIMENTAL_API sentry_span_t *sentry_span_start_child_n(
  * span.
  */
 SENTRY_EXPERIMENTAL_API void sentry_span_finish(sentry_span_t *span);
+/**
+ * Also finishes a span like the regular `sentry_span_finish` function, but has
+ * an additional timestamp parameter to let the user provide explicit timings.
+ *
+ * The timestamp should be provided in microseconds since the Unix epoch.
+ */
+SENTRY_EXPERIMENTAL_API void sentry_span_finish_ts(
+    sentry_span_t *span, uint64_t timestamp);
 
 /**
  * Sets a tag on a Transaction to the given string value.

src/sentry_core.c

@@ -842,6 +842,14 @@ sentry_set_level(sentry_level_t level)
 sentry_transaction_t *
 sentry_transaction_start(
     sentry_transaction_context_t *opaque_tx_cxt, sentry_value_t sampling_ctx)
+{
+    return sentry_transaction_start_ts(
+        opaque_tx_cxt, sampling_ctx, sentry__usec_time());
+}
+
+sentry_transaction_t *
+sentry_transaction_start_ts(sentry_transaction_context_t *opaque_tx_cxt,
+    sentry_value_t sampling_ctx, uint64_t timestamp)
 {
     // Just free this immediately until we implement proper support for
     // traces_sampler.
@@ -874,14 +882,21 @@ sentry_transaction_start(
 
     sentry_value_set_by_key(tx, "start_timestamp",
         sentry__value_new_string_owned(
-            sentry__usec_time_to_iso8601(sentry__usec_time())));
+            sentry__usec_time_to_iso8601(timestamp)));
 
     sentry__transaction_context_free(opaque_tx_cxt);
     return sentry__transaction_new(tx);
 }
 
 sentry_uuid_t
 sentry_transaction_finish(sentry_transaction_t *opaque_tx)
+{
+    return sentry_transaction_finish_ts(opaque_tx, sentry__usec_time());
+}
+
+sentry_uuid_t
+sentry_transaction_finish_ts(
+    sentry_transaction_t *opaque_tx, uint64_t timestamp)
 {
     if (!opaque_tx || sentry_value_is_null(opaque_tx->inner)) {
         SENTRY_DEBUG("no transaction available to finish");
@@ -919,7 +934,7 @@ sentry_transaction_finish(sentry_transaction_t *opaque_tx)
     sentry_value_set_by_key(tx, "type", sentry_value_new_string("transaction"));
     sentry_value_set_by_key(tx, "timestamp",
         sentry__value_new_string_owned(
-            sentry__usec_time_to_iso8601(sentry__usec_time())));
+            sentry__usec_time_to_iso8601(timestamp)));
     // TODO: This might not actually be necessary. Revisit after talking to
     // the relay team about this.
     sentry_value_set_by_key(tx, "level", sentry_value_new_string("info"));
@@ -987,6 +1002,24 @@ sentry_span_t *
 sentry_transaction_start_child_n(sentry_transaction_t *opaque_parent,
     const char *operation, size_t operation_len, const char *description,
     size_t description_len)
+{
+    return sentry_transaction_start_child_ts_n(opaque_parent, operation,
+        operation_len, description, description_len, sentry__usec_time());
+}
+
+sentry_span_t *
+sentry_transaction_start_child(sentry_transaction_t *opaque_parent,
+    const char *operation, const char *description)
+{
+    return sentry_transaction_start_child_n(opaque_parent, operation,
+        sentry__guarded_strlen(operation), description,
+        sentry__guarded_strlen(description));
+}
+
+sentry_span_t *
+sentry_transaction_start_child_ts_n(sentry_transaction_t *opaque_parent,
+    const char *operation, size_t operation_len, const char *description,
+    size_t description_len, const uint64_t timestamp)
 {
     if (!opaque_parent || sentry_value_is_null(opaque_parent->inner)) {
         SENTRY_DEBUG("no transaction available to create a child under");
@@ -1003,22 +1036,40 @@ sentry_transaction_start_child_n(sentry_transaction_t *opaque_parent,
 
     sentry_value_t span = sentry__value_span_new_n(max_spans, parent,
         (sentry_slice_t) { operation, operation_len },
-        (sentry_slice_t) { description, description_len });
+        (sentry_slice_t) { description, description_len }, timestamp);
     return sentry__span_new(opaque_parent, span);
 }
 
 sentry_span_t *
-sentry_transaction_start_child(sentry_transaction_t *opaque_parent,
-    const char *operation, const char *description)
+sentry_transaction_start_child_ts(sentry_transaction_t *opaque_parent,
+    const char *operation, const char *description, const uint64_t timestamp)
 {
-    return sentry_transaction_start_child_n(opaque_parent, operation,
+    return sentry_transaction_start_child_ts_n(opaque_parent, operation,
         sentry__guarded_strlen(operation), description,
-        sentry__guarded_strlen(description));
+        sentry__guarded_strlen(description), timestamp);
 }
 
 sentry_span_t *
 sentry_span_start_child_n(sentry_span_t *opaque_parent, const char *operation,
     size_t operation_len, const char *description, size_t description_len)
+{
+    return sentry_span_start_child_ts_n(opaque_parent, operation, operation_len,
+        description, description_len, sentry__usec_time());
+}
+
+sentry_span_t *
+sentry_span_start_child(sentry_span_t *opaque_parent, const char *operation,
+    const char *description)
+{
+    return sentry_span_start_child_n(opaque_parent, operation,
+        sentry__guarded_strlen(operation), description,
+        sentry__guarded_strlen(description));
+}
+
+sentry_span_t *
+sentry_span_start_child_ts_n(sentry_span_t *opaque_parent,
+    const char *operation, size_t operation_len, const char *description,
+    size_t description_len, uint64_t timestamp)
 {
     if (!opaque_parent || sentry_value_is_null(opaque_parent->inner)) {
         SENTRY_DEBUG("no parent span available to create a child span under");
@@ -1039,22 +1090,28 @@ sentry_span_start_child_n(sentry_span_t *opaque_parent, const char *operation,
 
     sentry_value_t span = sentry__value_span_new_n(max_spans, parent,
         (sentry_slice_t) { operation, operation_len },
-        (sentry_slice_t) { description, description_len });
+        (sentry_slice_t) { description, description_len }, timestamp);
 
     return sentry__span_new(opaque_parent->transaction, span);
 }
 
 sentry_span_t *
-sentry_span_start_child(sentry_span_t *opaque_parent, const char *operation,
-    const char *description)
+sentry_span_start_child_ts(sentry_span_t *opaque_parent, const char *operation,
+    const char *description, uint64_t timestamp)
 {
-    return sentry_span_start_child_n(opaque_parent, operation,
+    return sentry_span_start_child_ts_n(opaque_parent, operation,
         sentry__guarded_strlen(operation), description,
-        sentry__guarded_strlen(description));
+        sentry__guarded_strlen(description), timestamp);
 }
 
 void
 sentry_span_finish(sentry_span_t *opaque_span)
+{
+    sentry_span_finish_ts(opaque_span, sentry__usec_time());
+}
+
+void
+sentry_span_finish_ts(sentry_span_t *opaque_span, uint64_t timestamp)
 {
     if (!opaque_span || sentry_value_is_null(opaque_span->inner)) {
         SENTRY_DEBUG("no span to finish");
@@ -1118,7 +1175,7 @@ sentry_span_finish(sentry_span_t *opaque_span)
 
     sentry_value_set_by_key(span, "timestamp",
         sentry__value_new_string_owned(
-            sentry__usec_time_to_iso8601(sentry__usec_time())));
+            sentry__usec_time_to_iso8601(timestamp)));
     sentry_value_remove_by_key(span, "sampled");
 
     size_t max_spans = SENTRY_SPANS_MAX;

src/sentry_tracing.c

@@ -356,7 +356,7 @@ sentry__span_new(sentry_transaction_t *tx, sentry_value_t inner)
 
 sentry_value_t
 sentry__value_span_new_n(size_t max_spans, sentry_value_t parent,
-    sentry_slice_t operation, sentry_slice_t description)
+    sentry_slice_t operation, sentry_slice_t description, uint64_t timestamp)
 {
     if (!sentry_value_is_null(sentry_value_get_by_key(parent, "timestamp"))) {
         SENTRY_DEBUG("span's parent is already finished, not creating span");
@@ -378,7 +378,7 @@ sentry__value_span_new_n(size_t max_spans, sentry_value_t parent,
         sentry_value_new_string_n(description.ptr, description.len));
     sentry_value_set_by_key(child, "start_timestamp",
         sentry__value_new_string_owned(
-            sentry__usec_time_to_iso8601(sentry__usec_time())));
+            sentry__usec_time_to_iso8601(timestamp)));
 
     return child;
 fail:
@@ -387,10 +387,11 @@ sentry__value_span_new_n(size_t max_spans, sentry_value_t parent,
 
 sentry_value_t
 sentry__value_span_new(size_t max_spans, sentry_value_t parent,
-    const char *operation, const char *description)
+    const char *operation, const char *description, uint64_t timestamp)
 {
     return sentry__value_span_new_n(max_spans, parent,
-        sentry__slice_from_str(operation), sentry__slice_from_str(description));
+        sentry__slice_from_str(operation), sentry__slice_from_str(description),
+        timestamp);
 }
 
 sentry_value_t

src/sentry_tracing.h

@@ -37,9 +37,9 @@ void sentry__span_incref(sentry_span_t *span);
 void sentry__span_decref(sentry_span_t *span);
 
 sentry_value_t sentry__value_span_new(size_t max_spans, sentry_value_t parent,
-    const char *operation, const char *description);
+    const char *operation, const char *description, uint64_t timestamp);
 sentry_value_t sentry__value_span_new_n(size_t max_spans, sentry_value_t parent,
-    sentry_slice_t operation, sentry_slice_t description);
+    sentry_slice_t operation, sentry_slice_t description, uint64_t timestamp);
 
 sentry_span_t *sentry__span_new(
     sentry_transaction_t *parent_tx, sentry_value_t inner);

tests/assertions.py

@@ -205,8 +205,9 @@ def assert_minidump(envelope):
     assert minidump.payload.bytes.startswith(b"MDMP")
 
 
-def assert_timestamp(ts, now=datetime.now(UTC)):
-    assert ts[:11] == now.isoformat()[:11]
+def assert_timestamp(ts):
+    elapsed_time = datetime.now(UTC) - datetime.fromisoformat(ts)
+    assert elapsed_time.total_seconds() < 10
 
 
 def assert_event(envelope, message="Hello World!"):