feat(logs): add sentry log API + send first logs #1272
Conversation
|
| char conversion = *fmt_ptr; | ||
| if (conversion) { | ||
| char key[64]; | ||
| snprintf(key, sizeof(key), "sentry.message.parameter.%d", |
There was a problem hiding this comment.
Look into why other SDKs are using this too (instead of parameter.name); could be useful to track the variable over time across log statements. Probably hard to parse this in Native though.
-> insofar no usage of -> Python does this, see comment below.sentry.message.parameter.X found where X is not an integer. Will have to ask around internally.
There was a problem hiding this comment.
The Python SDK seems to be be doing this for f-strings, but in some integrations it's not always showing up as parameter.X (see getsentry/sentry-python#4525).
As mentioned in #1272 (review), providing a separate interface in Native that allows for these kinds of named parameters could be a potential improvement that will be part of the next Logs PR (after full initial implementation is finished, including batching).
|
temporarily back to draft, seems like we have some memory leaks 🧠 💧 |
JoshuaMoelans
force-pushed
the
joshua/feat/logs_logger_module
branch
from
26be7ca to
e75f60c
Compare
|
@sentry review |
|
On it! We are reviewing the PR and will provide feedback shortly. |
PR DescriptionThis pull request introduces a new structured logging feature to the Sentry Native SDK. The goal is to enable more detailed and contextual logging within applications using the SDK, allowing for better debugging and diagnostics of issues reported to Sentry. Click to see moreKey Technical ChangesThe key changes include: 1) Addition of new Architecture DecisionsThe primary architectural decision is to treat logs as a separate item type within the Sentry envelope, similar to events and transactions. This allows for efficient transport and processing of log data alongside other Sentry data. The log messages are structured as Sentry values (objects and lists) to facilitate querying and analysis within the Sentry platform. The implementation uses variadic functions for the logging API, which requires careful handling of format strings to prevent security vulnerabilities. The decision was made to send logs immediately rather than batching them, with a TODO comment indicating that batching should be implemented later. Dependencies and InteractionsThis feature depends on the existing Sentry core functionality, including Risk ConsiderationsPotential risks include: 1) Performance overhead of constructing and sending log messages, especially in high-volume scenarios. 2) Security vulnerabilities related to format string handling in the variadic logging functions. 3) Increased bandwidth usage due to the additional log data being sent to Sentry. 4) The immediate sending of logs without batching could lead to rate limiting issues. 5) The current implementation doesn't filter logs based on level, which could lead to excessive logging if trace level is enabled in production. Notable Implementation DetailsThe |
![seer-by-sentry[bot]](https://avatars.githubusercontent.com/in/801464?s=60&v=4){kind=small}
There was a problem hiding this comment.
That is a great start! I might give this another go tomorrow, but there are already a couple of points to address.
I did not explicitly mention the alternative interface for the format parameters (except for a concrete point where it overlaps with this PR, at least in terms of design effect)
src/sentry_logs.c
Outdated
| unsigned int val = va_arg(args_copy, unsigned int); | ||
| sentry_value_set_by_key(param_obj, "value", | ||
| sentry_value_new_int32((int32_t)val)); | ||
| sentry_value_set_by_key( | ||
| param_obj, "type", sentry_value_new_string("integer")); | ||
| break; |
There was a problem hiding this comment.
We must be cautious here: if you skip the length specifiers, a 64-bit value could be passed in. Even if the value is a 32-bit unsigned, there is no way the backend could know that this is an int32 containing a uint32 without an explicit protocol.
Essentially, if we accept unsigned integers of 32-bit, we'd have to store them in a double.
If we accept 64-bit unsigned integers, it must be clear that JSON will overflow numbers above 2^53-1
There was a problem hiding this comment.
By the way, introducing sentry_value_t (a list of kv-objects) as a parameter to format strings would also introduce some normalization (or put the burden of providing parameters that map to the sentry payloads on the user, instead of the code having to guess) in terms of the data that users can pass in here.
src/sentry_logs.c
Outdated
| case 'd': | ||
| case 'i': { | ||
| int val = va_arg(args_copy, int); | ||
| sentry_value_set_by_key( | ||
| param_obj, "value", sentry_value_new_int32(val)); | ||
| sentry_value_set_by_key( | ||
| param_obj, "type", sentry_value_new_string("integer")); | ||
| break; |
There was a problem hiding this comment.
Same as below... since you are skipping length, this could be a 64-bit signed integer.
* add (u)int64 sentry_value_t type * add value_to_msgpack missing switch cases * remove undefined behavior test (C99 6.3.1.4) * avoid Windows sized integer name collision * cleanup & apply code review feedback * more cleanup & remove type coercion
* add sentry logs option * add sentry logs option to example * feat(logs): add sentry log API + send first logs (#1272) * add sentry log API + send first logs * fix log_level_as_string * attach attributes to logs * attach formatted message + args * add to example * add more attributes * cleanup * windows warning-as-error * windows warning-as-error v2 * windows warning-as-error v2 (final) * add unit tests for initial logs * memleak attempted fix * memleak attempted fix 2 * cleanup * use `sentry_level_t` instead of new log level enum * add SENTRY_LEVEL_TRACE to sentry_logger * quick anti-brownout fix - see #1274 * fix missing SENTRY_LEVEL_INFO string return * fix logger level check + add test * cleanup logs parameter extraction * warn-as-error fix * const char* fix * static function * feat(logs): add (u)int64 sentry_value_t type (#1301) * add (u)int64 sentry_value_t type * add value_to_msgpack missing switch cases * remove undefined behavior test (C99 6.3.1.4) * avoid Windows sized integer name collision * cleanup & apply code review feedback * more cleanup & remove type coercion * update logs param conversion * own uint64 string * apply suggestions from code review * fixed log parameter conversion * update example to avoid warning-as-error * feat(logs): batching (#1338) * initial queue attempt * add timer * prototype double buffer approach * update logs unit tests for batching * replace timer with bgworker * add first integration tests * update example.c with correct log thread amounts * cleanup * add wait for 'adding' logs in flush logic * go back to single queue for performance testing * add time checks * add ToDos + cleanup sentry_value_t cloning * initial attempt * cond_wait for timer + 'adding' spinlock * add sleep for tests * add sleep for tests * force flush before attempting timer_worker shutdown * add proper cond_wait for 'adding' counter * revert to manual flush on shutdown instead of timer thread flush * add separate timer_stop atomic * cleanup + replace 'adding' cond_wait by pure spinlock * change bgworker for simpler thread implementation * cleanup * fix memleak * fixes * cleanup * cleanup * windows fixes * update shutdown order * fixes * explicit check to stop timer task * windows cleanup * loosen threaded test assertion for CI - too much variability in thread scheduling, so we can expect pretty much anything * add continue for unexpected logs flush trigger instead of attempting flush * Windows re-add condition variable trigger case * feat(logs): add `before_send_log` (#1355) * add `before_send_log` callback * add `before_send_log` callback tests * (temporary) add debug for calling sentry_options_free * remove early return * add late return * cleanup * fix ownership issues in single buffer batching (#1362) * let the producer thread sleep for 1ms between logs * fix two missing NULL checks in the json serializer * clean up logging and early exits in `enqueue_log_single()` * clean up ownerships in logs * eliminate clones (we expect that everything outlives the logs being sent except local construction) * use incref everywhere where we ref global state. this was the cause of the UAF, partially solved with the clones but a few were missing. no reason to clone if we do not want to disconnect for a particular object graph * clarify that add_attribute expects ownership * minimize scope_mut by moving os_context out * raise that log output in throughput tests add to variability (stdout logging should be turned off when running a limit) * log error in case we weren't able to start the log batching worker * fix clang-cl warning * ci: fix failing mingw build (#1361) * ci: fix failing mingw build * split `ASM_MASM_COMPILER` and `_FLAGS` * add `ASM_MASM_FLAGS` in `mingw` install step * specify the `CMAKE_ASM_MASM_COMPILER` as a `FILEPATH` * clean up CMAKE_DEFINES construction so it is easier to diff in the future * fix `LLVM_MINGW_INSTALL_PATH` to be referenced locally rather than $env (cherry picked from commit 519554f) * use UNREACHABLE macro to fix anal warnings * batching double buffered (#1365) * first attempt at double buffered * remove the sleep from the windows thread func * clean up thread waiting in the example * adapt the double buffer to use retries, fix remaining issues, clean up and write inline docs * return early in example on sentry_init error. * fix formatting via shorter name for thread gate atomic * improve inline docs of log_buffer_t members * fetch os_context from scope * move scope/options data retrieval into separate function + add expected keys to test * update logs API to return status code * cleanup * add log-event trace connection test * remove duplicate test * specify macOS SDKROOT --------- Co-authored-by: JoshuaMoelans <[email protected]> * add flush retry for missed flush requests * move flush retry into flush function * add docs --------- Co-authored-by: Mischan Toosarani-Hausberger <[email protected]> * update CHANGELOG.md * use `trace_id` from scoped spans for logs * fix copy-paste leftover + docs * add log_sleep for thread test + variable NUM_LOGS * no `usleep` on windows :( * fix seconds->milliseconds * cleanup * test(logs): add 32-bit vargs test (#1370) * add vargs conversion test * add ifdef for 32-bit systems * Update tests/unit/test_logs.c Co-authored-by: Mischan Toosarani-Hausberger <[email protected]> * add comment * fix comment --------- Co-authored-by: Mischan Toosarani-Hausberger <[email protected]> * Apply suggestions from code review Co-authored-by: Mischan Toosarani-Hausberger <[email protected]> * post-merge cleanup * pin ruamel version * let's unpin ruamel.yaml.clib to get 0.2.14 which seemingly fixes the missing header: https://sourceforge.net/p/ruamel-yaml-clib/tickets/47/#de77 * add empty payload check * log output of logger tests if we fail to find the pre-crash marker * fix: move `is_tsan` marker into the `has_crashpad` condition... ...so we can ignore in which module a `crashpad` test runs. * fix: update `has_crashpad` condition comment * really only move `is_tsan`, but keep the module level `pytestmark` * CHANGELOG.md update * CHANGELOG.md update * CHANGELOG.md update --------- Co-authored-by: Mischan Toosarani-Hausberger <[email protected]>
First step towards #1210 (Merging into #1271)
Adds the initial logs API
sentry_log_X(...)and constructs envelopes with the appropriate date & attributes. Currently sends these one at a time (for each API call), so next PR will be adding batching for logs.Example usage:
The 'first logs' visible on Sentry
#skip-changelog