feat: structured logging

CHANGELOG.md

@@ -6,6 +6,10 @@
 
 - Add `user_data` parameter to `traces_sampler`. ([#1346](https://github.com/getsentry/sentry-native/pull/1346))
 
+**Features**:
+
+- Add support for structured logs. ([#1271](https://github.com/getsentry/sentry-native/pull/1271/))
+
 **Internal:**
 
 - Support downstream Xbox SDK specifying networking initialization mechanism. ([#1359](https://github.com/getsentry/sentry-native/pull/1359))

examples/example.c

@@ -24,6 +24,7 @@
 #    define sleep_s(SECONDS) Sleep((SECONDS) * 1000)
 #else
 
+#    include <pthread.h>
 #    include <signal.h>
 #    include <unistd.h>
 
@@ -158,6 +159,33 @@ discarding_before_transaction_callback(sentry_value_t tx, void *user_data)
     return tx;
 }
 
+static sentry_value_t
+before_send_log_callback(sentry_value_t log, void *user_data)
+{
+    (void)user_data;
+    sentry_value_t attribute = sentry_value_new_object();
+    sentry_value_set_by_key(
+        attribute, "value", sentry_value_new_string("little"));
+    sentry_value_set_by_key(
+        attribute, "type", sentry_value_new_string("string"));
+    sentry_value_set_by_key(sentry_value_get_by_key(log, "attributes"),
+        "coffeepot.size", attribute);
+    return log;
+}
+
+static sentry_value_t
+discarding_before_send_log_callback(sentry_value_t log, void *user_data)
+{
+    (void)user_data;
+    if (sentry_value_is_null(
+            sentry_value_get_by_key(sentry_value_get_by_key(log, "attributes"),
+                "sentry.message.template"))) {
+        sentry_value_decref(log);
+        return sentry_value_new_null();
+    }
+    return log;
+}
+
 static void
 print_envelope(sentry_envelope_t *envelope, void *unused_state)
 {
@@ -275,6 +303,42 @@ create_debug_crumb(const char *message)
     return debug_crumb;
 }
 
+#define NUM_THREADS 50
+#define NUM_LOGS 100 // how many log calls each thread makes
+#define LOG_SLEEP_MS 1 // time (in ms) between log calls
+
+#if defined(SENTRY_PLATFORM_WINDOWS)
+#    define sleep_ms(MILLISECONDS) Sleep(MILLISECONDS)
+#else
+#    define sleep_ms(MILLISECONDS) usleep(MILLISECONDS * 1000)
+#endif
+
+#ifdef SENTRY_PLATFORM_WINDOWS
+DWORD WINAPI
+log_thread_func(LPVOID lpParam)
+{
+    (void)lpParam;
+    for (int i = 0; i < NUM_LOGS; i++) {
+        sentry_log_debug(
+            "thread log %d on thread %lu", i, get_current_thread_id());
+        sleep_ms(LOG_SLEEP_MS);
+    }
+    return 0;
+}
+#else
+void *
+log_thread_func(void *arg)
+{
+    (void)arg;
+    for (int i = 0; i < NUM_LOGS; i++) {
+        sentry_log_debug(
+            "thread log %d on thread %llu", i, get_current_thread_id());
+        sleep_ms(LOG_SLEEP_MS);
+    }
+    return NULL;
+}
+#endif
+
 int
 main(int argc, char **argv)
 {
@@ -348,6 +412,16 @@ main(int argc, char **argv)
             options, discarding_before_transaction_callback, NULL);
     }
 
+    if (has_arg(argc, argv, "before-send-log")) {
+        sentry_options_set_before_send_log(
+            options, before_send_log_callback, NULL);
+    }
+
+    if (has_arg(argc, argv, "discarding-before-send-log")) {
+        sentry_options_set_before_send_log(
+            options, discarding_before_send_log_callback, NULL);
+    }
+
     if (has_arg(argc, argv, "traces-sampler")) {
         sentry_options_set_traces_sampler(
             options, traces_sampler_callback, NULL);
@@ -385,14 +459,59 @@ main(int argc, char **argv)
         sentry_options_add_view_hierarchy(options, "./view-hierarchy.json");
     }
 
-    sentry_init(options);
+    if (has_arg(argc, argv, "enable-logs")) {
+        sentry_options_set_enable_logs(options, true);
+    }
+
+    if (0 != sentry_init(options)) {
+        return EXIT_FAILURE;
+    }
 
     if (has_arg(argc, argv, "attachment")) {
         sentry_attachment_t *bytes
             = sentry_attach_bytes("\xc0\xff\xee", 3, "bytes.bin");
         sentry_attachment_set_content_type(bytes, "application/octet-stream");
     }
 
+    if (sentry_options_get_enable_logs(options)) {
+        if (has_arg(argc, argv, "capture-log")) {
+            sentry_log_debug("I'm a log message!");
+        }
+        if (has_arg(argc, argv, "logs-timer")) {
+            for (int i = 0; i < 10; i++) {
+                sentry_log_info("Informational log nr.%d", i);
+            }
+            // sleep >5s to trigger logs timer
+            sleep_s(6);
+            // we should see two envelopes make its way to Sentry
+            sentry_log_debug("post-sleep log");
+        }
+        if (has_arg(argc, argv, "logs-threads")) {
+            // Spawn multiple threads to test concurrent logging
+#ifdef SENTRY_PLATFORM_WINDOWS
+            HANDLE threads[NUM_THREADS];
+            for (int t = 0; t < NUM_THREADS; t++) {
+                threads[t]
+                    = CreateThread(NULL, 0, log_thread_func, NULL, 0, NULL);
+            }
+
+            WaitForMultipleObjects(NUM_THREADS, threads, TRUE, INFINITE);
+
+            for (int t = 0; t < NUM_THREADS; t++) {
+                CloseHandle(threads[t]);
+            }
+#else
+            pthread_t threads[NUM_THREADS];
+            for (int t = 0; t < NUM_THREADS; t++) {
+                pthread_create(&threads[t], NULL, log_thread_func, NULL);
+            }
+            for (int t = 0; t < NUM_THREADS; t++) {
+                pthread_join(threads[t], NULL);
+            }
+#endif
+        }
+    }
+
     if (!has_arg(argc, argv, "no-setup")) {
         sentry_set_transaction("test-transaction");
         sentry_set_level(SENTRY_LEVEL_WARNING);
@@ -633,9 +752,15 @@ main(int argc, char **argv)
             sentry_value_t event = sentry_value_new_message_event(
                 SENTRY_LEVEL_INFO, "my-logger", "Hello World!");
             sentry_capture_event(event);
+            if (has_arg(argc, argv, "logs-scoped-transaction")) {
+                sentry_log_debug("logging during scoped transaction event");
+            }
         }
 
         sentry_transaction_finish(tx);
+        if (has_arg(argc, argv, "logs-scoped-transaction")) {
+            sentry_log_debug("logging after scoped transaction event");
+        }
     }
 
     if (has_arg(argc, argv, "capture-minidump")) {
@@ -652,4 +777,6 @@ main(int argc, char **argv)
     if (has_arg(argc, argv, "crash-after-shutdown")) {
         trigger_crash();
     }
+
+    return EXIT_SUCCESS;
 }

include/sentry.h

@@ -442,6 +442,7 @@ SENTRY_API char *sentry_value_to_json(sentry_value_t value);
  * Sentry levels for events and breadcrumbs.
  */
 typedef enum sentry_level_e {
+    SENTRY_LEVEL_TRACE = -2,
     SENTRY_LEVEL_DEBUG = -1,
     SENTRY_LEVEL_INFO = 0,
     SENTRY_LEVEL_WARNING = 1,
@@ -1880,6 +1881,83 @@ SENTRY_EXPERIMENTAL_API void sentry_options_set_traces_sampler(
     sentry_options_t *opts, sentry_traces_sampler_function callback,
     void *user_data);
 
+/**
+ * Enables or disables the structured logging feature.
+ * When disabled, all calls to sentry_logger_X() are no-ops.
+ */
+SENTRY_EXPERIMENTAL_API void sentry_options_set_enable_logs(
+    sentry_options_t *opts, int enable_logs);
+SENTRY_EXPERIMENTAL_API int sentry_options_get_enable_logs(
+    const sentry_options_t *opts);
+
+/**
+ * The potential returns of calling any of the sentry_logs_X functions
+ * - Success means a log was enqueued
+ * - Discard means the `before_send_log` function discarded the log
+ * - Failed means the log wasn't enqueued. This happens if the buffers are full
+ * - Disabled means the option `enable_logs` was false.
+ */
+typedef enum {
+    SENTRY_LOG_RETURN_SUCCESS = 0,
+    SENTRY_LOG_RETURN_DISCARD = 1,
+    SENTRY_LOG_RETURN_FAILED = 2,
+    SENTRY_LOG_RETURN_DISABLED = 3
+} log_return_value_t;
+
+/**
+ * Structured logging interface. Minimally blocks the client trying to log,
+ * but is therefor lossy when enqueueing a log fails
+ * (e.g. when both buffers are full).
+ *
+ * Format string restrictions:
+ * Only a subset of printf format specifiers are supported for parameter
+ * extraction. Supported specifiers include:
+ * - %d, %i - signed integers (treated as long long)
+ * - %u, %x, %X, %o - unsigned integers (treated as unsigned long long)
+ * - %f, %F, %e, %E, %g, %G - floating point numbers (treated as double)
+ * - %c - single character
+ * - %s - null-terminated string (null pointers are handled as "(null)")
+ * - %p - pointer value (formatted as hexadecimal string)
+ *
+ * Unsupported format specifiers will consume their corresponding argument
+ * but will be recorded as "(unknown)" in the structured log data.
+ * Length modifiers (h, l, L, z, j, t) are parsed but ignored.
+ *
+ * Because of this, please only use 64-bit types for parameters.
+ *
+ * Flags, width, and precision specifiers are parsed but currently ignored for
+ * parameter extraction purposes.
+ */
+SENTRY_EXPERIMENTAL_API log_return_value_t sentry_log_trace(
+    const char *message, ...);
+SENTRY_EXPERIMENTAL_API log_return_value_t sentry_log_debug(
+    const char *message, ...);
+SENTRY_EXPERIMENTAL_API log_return_value_t sentry_log_info(
+    const char *message, ...);
+SENTRY_EXPERIMENTAL_API log_return_value_t sentry_log_warn(
+    const char *message, ...);
+SENTRY_EXPERIMENTAL_API log_return_value_t sentry_log_error(
+    const char *message, ...);
+SENTRY_EXPERIMENTAL_API log_return_value_t sentry_log_fatal(
+    const char *message, ...);
+
+/**
+ * Type of the `before_send_log` callback.
+ *
+ * The callback takes ownership of the `log`, and should usually return
+ * that same log. In case the log should be discarded, the
+ * callback needs to call `sentry_value_decref` on the provided log, and
+ * return a `sentry_value_new_null()` instead.
+ */
+typedef sentry_value_t (*sentry_before_send_log_function_t)(
+    sentry_value_t log, void *user_data);
+
+/**
+ * Sets the `before_send_log` callback.
+ */
+SENTRY_EXPERIMENTAL_API void sentry_options_set_before_send_log(
+    sentry_options_t *opts, sentry_before_send_log_function_t func, void *data);
+
 #ifdef SENTRY_PLATFORM_LINUX
 
 /**

src/CMakeLists.txt

@@ -17,6 +17,8 @@ sentry_target_sources_cwd(sentry
 	sentry_json.h
 	sentry_logger.c
 	sentry_logger.h
+	sentry_logs.c
+	sentry_logs.h
 	sentry_options.c
 	sentry_options.h
 	sentry_os.c

src/sentry_core.c

@@ -8,6 +8,7 @@
 #include "sentry_core.h"
 #include "sentry_database.h"
 #include "sentry_envelope.h"
+#include "sentry_logs.h"
 #include "sentry_options.h"
 #include "sentry_path.h"
 #include "sentry_random.h"
@@ -164,6 +165,7 @@ sentry_init(sentry_options_t *options)
     sentry_close();
 
     sentry_logger_t logger = { NULL, NULL, SENTRY_LEVEL_DEBUG };
+
     if (options->debug) {
         logger = options->logger;
     }
@@ -286,6 +288,10 @@ sentry_init(sentry_options_t *options)
         sentry_start_session();
     }
 
+    if (options->enable_logs) {
+        sentry__logs_startup();
+    }
+
     sentry__mutex_unlock(&g_options_lock);
     return 0;
 
@@ -312,6 +318,15 @@ sentry_flush(uint64_t timeout)
 int
 sentry_close(void)
 {
+    // Shutdown logs system before locking options to ensure logs are flushed.
+    // This prevents a potential deadlock on the options during log envelope
+    // creation.
+    SENTRY_WITH_OPTIONS (options) {
+        if (options->enable_logs) {
+            sentry__logs_shutdown(options->shutdown_timeout);
+        }
+    }
+
     SENTRY__MUTEX_INIT_DYN_ONCE(g_options_lock);
     // this function is to be called only once, so we do not allow more than one
     // caller

src/sentry_envelope.c

@@ -265,6 +265,9 @@ sentry__envelope_add_event(sentry_envelope_t *envelope, sentry_value_t event)
     item->event = event;
     sentry__jsonwriter_write_value(jw, event);
     item->payload = sentry__jsonwriter_into_string(jw, &item->payload_len);
+    if (!item->payload) {
+        return NULL;
+    }
 
     sentry__envelope_item_set_header(
         item, "type", sentry_value_new_string("event"));
@@ -401,6 +404,35 @@ sentry__envelope_add_transaction(
     return item;
 }
 
+sentry_envelope_item_t *
+sentry__envelope_add_logs(sentry_envelope_t *envelope, sentry_value_t logs)
+{
+    sentry_envelope_item_t *item = envelope_add_item(envelope);
+    if (!item) {
+        return NULL;
+    }
+
+    sentry_jsonwriter_t *jw = sentry__jsonwriter_new_sb(NULL);
+    if (!jw) {
+        return NULL;
+    }
+
+    sentry__jsonwriter_write_value(jw, logs);
+    item->payload = sentry__jsonwriter_into_string(jw, &item->payload_len);
+
+    sentry__envelope_item_set_header(
+        item, "type", sentry_value_new_string("log"));
+    sentry__envelope_item_set_header(item, "item_count",
+        sentry_value_new_int32((int32_t)sentry_value_get_length(
+            sentry_value_get_by_key(logs, "items"))));
+    sentry__envelope_item_set_header(item, "content_type",
+        sentry_value_new_string("application/vnd.sentry.items.log+json"));
+    sentry_value_t length = sentry_value_new_int32((int32_t)item->payload_len);
+    sentry__envelope_item_set_header(item, "length", length);
+
+    return item;
+}
+
 sentry_envelope_item_t *
 sentry__envelope_add_user_report(
     sentry_envelope_t *envelope, sentry_value_t user_report)

src/sentry_envelope.h

@@ -49,6 +49,12 @@ sentry_envelope_item_t *sentry__envelope_add_transaction(
 sentry_envelope_item_t *sentry__envelope_add_user_report(
     sentry_envelope_t *envelope, sentry_value_t user_report);
 
+/**
+ * Add a list of logs to this envelope.
+ */
+sentry_envelope_item_t *sentry__envelope_add_logs(
+    sentry_envelope_t *envelope, sentry_value_t logs);
+
 /**
  * Add a user feedback to this envelope.
  */