From 6b8b2b2312db30e6b004ba6905c49ff0f8e2d422 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 13:10:17 +0200 Subject: [PATCH 01/21] Extend internal GrpcClient to cache a connected Channel --- Cargo.lock | 1 + liblogjet/include/liblogjet.h | 1 + liblogjet/src/lib.rs | 85 ++++++++++++++++++++++++++++++++++- 3 files changed, 85 insertions(+), 2 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 301c54d..e5d701a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1715,6 +1715,7 @@ name = "otlp-demo" version = "0.9.0" dependencies = [ "colored", + "liblogjet", "logjet", "lz4_flex", "opentelemetry-proto", diff --git a/liblogjet/include/liblogjet.h b/liblogjet/include/liblogjet.h index 10d11d8..705def4 100644 --- a/liblogjet/include/liblogjet.h +++ b/liblogjet/include/liblogjet.h @@ -156,6 +156,7 @@ const char *lj_error_message(void); lj_logger *lj_logger_new_http(const char *endpoint, const char *service_name, uint64_t timeout_ms); lj_logger *lj_logger_new_grpc(const char *endpoint, const char *service_name, uint64_t timeout_ms); bool lj_logger_log(lj_logger *logger, const lj_log_record *record); +bool lj_logger_log_reuse(lj_logger *logger, const lj_log_record *record); void lj_logger_free(lj_logger *logger); lj_ingest_plugin *lj_ingest_create(void); diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index 465a307..fd14db6 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -17,7 +17,7 @@ use opentelemetry_proto::tonic::resource::v1::Resource; use prost::Message; use tokio::runtime::{Builder, Runtime}; use tonic::Request; -use tonic::transport::Endpoint; +use tonic::transport::{Channel, Endpoint}; const LJ_ATTR_STRING: i32 = 0; const LJ_ATTR_INT: i32 = 1; @@ -98,6 +98,7 @@ struct HttpEndpoint { struct GrpcClient { endpoint: String, runtime: Mutex, + channel: Mutex>, } /// Returns the library version string. @@ -171,6 +172,43 @@ pub unsafe extern "C" fn lj_logger_log(logger: *mut lj_logger, record: *const Lj } } +/// Sends one log record, reusing a persistent connection. +/// +/// For gRPC loggers this reuses a cached channel, avoiding a fresh connection +/// handshake on every call. For HTTP loggers it currently behaves like +/// `lj_logger_log` (a new connection per call) until HTTP keep-alive lands. +/// +/// # Safety +/// +/// `logger` must be a valid pointer returned by `lj_logger_new_http` or +/// `lj_logger_new_grpc`. `record` must point to a valid `LjLogRecord` for the +/// duration of the call. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_log_reuse(logger: *mut lj_logger, record: *const LjLogRecord) -> bool { + clear_last_error(); + let logger = match unsafe { logger.as_mut() } { + Some(logger) => logger, + None => { + set_last_error("logger is null"); + return false; + } + }; + let record = match unsafe { record.as_ref() } { + Some(record) => record, + None => { + set_last_error("record is null"); + return false; + } + }; + match build_request(&logger.inner, record).and_then(|request| send_request_reuse(&logger.inner, request)) { + Ok(()) => true, + Err(err) => { + set_last_error(err); + false + } + } +} + /// Frees a logger created by one of the constructors. Accepts null. /// /// # Safety @@ -207,7 +245,9 @@ unsafe fn new_logger_impl(endpoint: *const c_char, service_name: *const c_char, let timeout = Duration::from_millis(timeout_ms.max(1)); let backend = match kind { BackendKind::Http => Backend::Http(parse_http_endpoint(&endpoint)?), - BackendKind::Grpc => Backend::Grpc(GrpcClient { endpoint: normalise_grpc_endpoint(&endpoint), runtime: Mutex::new(grpc_runtime()?) }), + BackendKind::Grpc => { + Backend::Grpc(GrpcClient { endpoint: normalise_grpc_endpoint(&endpoint), runtime: Mutex::new(grpc_runtime()?), channel: Mutex::new(None) }) + } }; Ok(Logger { backend, service_name, timeout }) } @@ -310,6 +350,47 @@ fn send_request(logger: &Logger, request: ExportLogsServiceRequest) -> Result<() } } +fn send_request_reuse(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { + match &logger.backend { + Backend::Http(endpoint) => post_otlp_http(endpoint, logger.timeout, &request).map_err(|err| err.to_string()), + Backend::Grpc(client) => send_otlp_grpc_pooled(client, logger.timeout, request), + } +} + +fn send_otlp_grpc_pooled(client: &GrpcClient, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { + let runtime = client.runtime.lock().map_err(|_| "gRPC runtime lock poisoned".to_string())?; + + let channel = { + let mut guard = client.channel.lock().map_err(|_| "gRPC channel lock poisoned".to_string())?; + match guard.as_ref() { + Some(channel) => channel.clone(), + None => { + let channel = runtime.block_on(connect_channel(&client.endpoint, timeout)).map_err(|err| err.to_string())?; + *guard = Some(channel.clone()); + channel + } + } + }; + + let result = runtime.block_on(export_on_channel(channel, request)); + if result.is_err() + && let Ok(mut guard) = client.channel.lock() + { + *guard = None; + } + result.map_err(|err| err.to_string()) +} + +async fn connect_channel(endpoint: &str, timeout: Duration) -> Result> { + Ok(Endpoint::from_shared(endpoint.to_string())?.timeout(timeout).connect_timeout(timeout).connect().await?) +} + +async fn export_on_channel(channel: Channel, request: ExportLogsServiceRequest) -> Result<(), Box> { + let mut client = LogsServiceClient::new(channel); + client.export(Request::new(request)).await?; + Ok(()) +} + async fn send_otlp_grpc(endpoint: String, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), Box> { let channel = Endpoint::from_shared(endpoint)?.timeout(timeout).connect_timeout(timeout).connect().await?; let mut client = LogsServiceClient::new(channel); From 32576d1bfae0007099eb481baac09039c4a1265f Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 13:34:11 +0200 Subject: [PATCH 02/21] Update ABI for batching and reusing the same connection --- liblogjet/include/liblogjet.h | 1 + liblogjet/src/lib.rs | 219 +++++++++++++++++++++++------ ljx/tests/unit/commands/view_ut.rs | 4 +- 3 files changed, 178 insertions(+), 46 deletions(-) diff --git a/liblogjet/include/liblogjet.h b/liblogjet/include/liblogjet.h index 705def4..5535c0c 100644 --- a/liblogjet/include/liblogjet.h +++ b/liblogjet/include/liblogjet.h @@ -157,6 +157,7 @@ lj_logger *lj_logger_new_http(const char *endpoint, const char *service_name, ui lj_logger *lj_logger_new_grpc(const char *endpoint, const char *service_name, uint64_t timeout_ms); bool lj_logger_log(lj_logger *logger, const lj_log_record *record); bool lj_logger_log_reuse(lj_logger *logger, const lj_log_record *record); +bool lj_logger_log_batch(lj_logger *logger, const lj_log_record *records, size_t len); void lj_logger_free(lj_logger *logger); lj_ingest_plugin *lj_ingest_create(void); diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index fd14db6..b3bd0fb 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -209,6 +209,43 @@ pub unsafe extern "C" fn lj_logger_log_reuse(logger: *mut lj_logger, record: *co } } +/// Sends a batch of records in a single export request over a persistent +/// connection. +/// +/// Records sharing the same effective service name, scope name, resource +/// attributes, and scope attributes are grouped into one `ScopeLogs`. A `len` +/// of `0` (or a null `records` pointer) is a successful no-op. For gRPC loggers +/// the batch is sent over the reused channel; HTTP loggers send one POST for +/// the whole batch. +/// +/// # Safety +/// +/// `logger` must be a valid pointer returned by `lj_logger_new_http` or +/// `lj_logger_new_grpc`. When `len > 0`, `records` must point to `len` valid +/// `LjLogRecord` values for the duration of the call. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_log_batch(logger: *mut lj_logger, records: *const LjLogRecord, len: usize) -> bool { + clear_last_error(); + let logger = match unsafe { logger.as_mut() } { + Some(logger) => logger, + None => { + set_last_error("logger is null"); + return false; + } + }; + if len == 0 || records.is_null() { + return true; + } + let records = unsafe { std::slice::from_raw_parts(records, len) }; + match build_batch_request(&logger.inner, records).and_then(|request| send_request_reuse(&logger.inner, request)) { + Ok(()) => true, + Err(err) => { + set_last_error(err); + false + } + } +} + /// Frees a logger created by one of the constructors. Accepts null. /// /// # Safety @@ -256,24 +293,115 @@ fn grpc_runtime() -> Result { Builder::new_multi_thread().enable_all().build().map_err(|err| err.to_string()) } +/// Raw `(key, value_type, value)` attribute triples read once from the C side. +type AttrTriples = Vec<(String, i32, String)>; +/// Grouping key for a resource: effective service name plus resource attributes. +type ResourceKey = (String, AttrTriples); +/// Grouping key for a scope: effective scope name plus scope attributes. +type ScopeKey = (String, AttrTriples); + fn build_request(logger: &Logger, record: &LjLogRecord) -> Result { + let (_, resource_attrs) = resolve_resource(logger, record)?; + let (_, scope) = resolve_scope(record)?; + let log = record_to_log(record)?; + + Ok(ExportLogsServiceRequest { + resource_logs: vec![ResourceLogs { + schema_url: String::new(), + resource: Some(Resource { attributes: resource_attrs, dropped_attributes_count: 0, entity_refs: Vec::new() }), + scope_logs: vec![ScopeLogs { schema_url: String::new(), scope: Some(scope), log_records: vec![log] }], + }], + }) +} + +fn build_batch_request(logger: &Logger, records: &[LjLogRecord]) -> Result { + use std::collections::HashMap; + + struct ScopeGroup { + scope: InstrumentationScope, + log_records: Vec, + } + struct ResourceGroup { + resource_attrs: Vec, + scopes: Vec, + scope_index: HashMap, + } + + let mut groups: Vec = Vec::new(); + let mut resource_index: HashMap = HashMap::new(); + + for record in records { + let (resource_key, resource_attrs) = resolve_resource(logger, record)?; + let (scope_key, scope) = resolve_scope(record)?; + let log = record_to_log(record)?; + + let resource_idx = match resource_index.get(&resource_key) { + Some(idx) => *idx, + None => { + groups.push(ResourceGroup { resource_attrs, scopes: Vec::new(), scope_index: HashMap::new() }); + let idx = groups.len() - 1; + resource_index.insert(resource_key, idx); + idx + } + }; + + let group = &mut groups[resource_idx]; + let scope_idx = match group.scope_index.get(&scope_key) { + Some(idx) => *idx, + None => { + group.scopes.push(ScopeGroup { scope, log_records: Vec::new() }); + let idx = group.scopes.len() - 1; + group.scope_index.insert(scope_key, idx); + idx + } + }; + group.scopes[scope_idx].log_records.push(log); + } + + Ok(ExportLogsServiceRequest { + resource_logs: groups + .into_iter() + .map(|group| ResourceLogs { + schema_url: String::new(), + resource: Some(Resource { attributes: group.resource_attrs, dropped_attributes_count: 0, entity_refs: Vec::new() }), + scope_logs: group + .scopes + .into_iter() + .map(|scope_group| ScopeLogs { schema_url: String::new(), scope: Some(scope_group.scope), log_records: scope_group.log_records }) + .collect(), + }) + .collect(), + }) +} + +fn resolve_resource(logger: &Logger, record: &LjLogRecord) -> Result<(ResourceKey, Vec), String> { let service_name = read_optional(record.service_name)?.unwrap_or_else(|| logger.service_name.clone()); if service_name.is_empty() { return Err("service name is empty".to_string()); } - let severity_text = read_optional(record.severity_text)?.unwrap_or_else(|| severity_text(record.severity_number).to_string()); - let body = read_required_nonnull(record.body, "record.body")?; - let event_name = read_optional(record.event_name)?.unwrap_or_default(); - let scope_name = read_optional(record.scope_name)?.unwrap_or_else(|| DEFAULT_SCOPE_NAME.to_string()); - - let mut resource_attrs = attrs_to_kvs(record.resource_attrs, record.resource_attrs_len)?; - if !resource_attrs.iter().any(|kv| kv.key == "service.name") { + let triples = read_attrs(record.resource_attrs, record.resource_attrs_len)?; + let mut resource_attrs = triples_to_kvs(&triples)?; + if !triples.iter().any(|(key, _, _)| key == "service.name") { resource_attrs.insert(0, key_value("service.name", AnyValue { value: Some(Value::StringValue(service_name.clone())) })); } - let scope_attrs = attrs_to_kvs(record.scope_attrs, record.scope_attrs_len)?; - let log_attrs = attrs_to_kvs(record.attributes, record.attributes_len)?; + Ok(((service_name, triples), resource_attrs)) +} + +fn resolve_scope(record: &LjLogRecord) -> Result<(ScopeKey, InstrumentationScope), String> { + let scope_name = read_optional(record.scope_name)?.unwrap_or_else(|| DEFAULT_SCOPE_NAME.to_string()); + let triples = read_attrs(record.scope_attrs, record.scope_attrs_len)?; + let scope_attrs = triples_to_kvs(&triples)?; + let scope = InstrumentationScope { name: scope_name.clone(), version: String::new(), attributes: scope_attrs, dropped_attributes_count: 0 }; + Ok(((scope_name, triples), scope)) +} + +fn record_to_log(record: &LjLogRecord) -> Result { + let severity_text = read_optional(record.severity_text)?.unwrap_or_else(|| severity_text(record.severity_number).to_string()); + let body = read_required_nonnull(record.body, "record.body")?; + let event_name = read_optional(record.event_name)?.unwrap_or_default(); + let log_attrs = triples_to_kvs(&read_attrs(record.attributes, record.attributes_len)?)?; let mut log = LogRecord { time_unix_nano: record.timestamp_unix_ns, @@ -291,47 +419,46 @@ fn build_request(logger: &Logger, record: &LjLogRecord) -> Result Result, String> { +fn read_attrs(attrs: *const LjAttribute, len: usize) -> Result { if len == 0 || attrs.is_null() { return Ok(Vec::new()); } let attrs = unsafe { std::slice::from_raw_parts(attrs, len) }; - attrs.iter().map(attr_to_kv).collect() -} - -fn attr_to_kv(attr: &LjAttribute) -> Result { - let key = read_required_nonnull(attr.key, "attribute.key")?; - let raw = read_required_nonnull(attr.value, "attribute.value")?; - let value = match attr.value_type { - LJ_ATTR_STRING => AnyValue { value: Some(Value::StringValue(raw)) }, - LJ_ATTR_INT => AnyValue { value: Some(Value::IntValue(raw.parse::().unwrap_or(0))) }, - LJ_ATTR_ARRAY => AnyValue { - value: Some(Value::ArrayValue(ArrayValue { - values: raw - .split(',') - .map(str::trim) - .filter(|part| !part.is_empty()) - .map(|part| AnyValue { value: Some(Value::StringValue(part.to_string())) }) - .collect(), - })), - }, - other => return Err(format!("unsupported attribute value_type {other}")), - }; - Ok(key_value(key, value)) + attrs + .iter() + .map(|attr| { + let key = read_required_nonnull(attr.key, "attribute.key")?; + let value = read_required_nonnull(attr.value, "attribute.value")?; + Ok((key, attr.value_type, value)) + }) + .collect() +} + +fn triples_to_kvs(triples: &[(String, i32, String)]) -> Result, String> { + triples + .iter() + .map(|(key, value_type, raw)| { + let value = match *value_type { + LJ_ATTR_STRING => AnyValue { value: Some(Value::StringValue(raw.clone())) }, + LJ_ATTR_INT => AnyValue { value: Some(Value::IntValue(raw.parse::().unwrap_or(0))) }, + LJ_ATTR_ARRAY => AnyValue { + value: Some(Value::ArrayValue(ArrayValue { + values: raw + .split(',') + .map(str::trim) + .filter(|part| !part.is_empty()) + .map(|part| AnyValue { value: Some(Value::StringValue(part.to_string())) }) + .collect(), + })), + }, + other => return Err(format!("unsupported attribute value_type {other}")), + }; + Ok(key_value(key.clone(), value)) + }) + .collect() } fn key_value(key: impl Into, value: AnyValue) -> KeyValue { @@ -492,3 +619,7 @@ fn set_last_error(message: impl Into) { *slot.borrow_mut() = CString::new(clean).unwrap_or_else(|_| CString::new("invalid error").expect("static")); }); } + +#[cfg(test)] +#[path = "../tests/unit/batch_ut.rs"] +mod batch_ut; diff --git a/ljx/tests/unit/commands/view_ut.rs b/ljx/tests/unit/commands/view_ut.rs index 37daf65..5331c25 100644 --- a/ljx/tests/unit/commands/view_ut.rs +++ b/ljx/tests/unit/commands/view_ut.rs @@ -115,7 +115,7 @@ fn modal_info_lists_otlp_attributes() { value: Some(Value::ArrayValue(opentelemetry_proto::tonic::common::v1::ArrayValue { values: vec![ AnyValue { value: Some(Value::StringValue("de".to_string())) }, - AnyValue { value: Some(Value::StringValue("eso".to_string())) }, + AnyValue { value: Some(Value::StringValue("demo".to_string())) }, ], })), }), @@ -159,7 +159,7 @@ fn modal_info_lists_otlp_attributes() { let entries = render_modal_info_entries(&detail); assert!(entries.iter().any(|(key, value)| key == "resource.service.name" && value == "cpp-appliance")); assert!(entries.iter().any(|(key, value)| key == "scope.demo.channel" && value == "de")); - assert!(entries.iter().any(|(key, value)| key.is_empty() && value == "eso")); + assert!(entries.iter().any(|(key, value)| key.is_empty() && value == "demo")); assert!(entries.iter().any(|(key, value)| key == "record.character" && value == "Bender")); } From 85a32b01a4c748723ceaf44c00cb8bc3d618617d Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 13:34:27 +0200 Subject: [PATCH 03/21] Add speed benchmark demo --- demo/Cargo.toml | 5 + demo/benchmark-clib/README.md | 44 +++++ demo/benchmark-clib/ljd.conf | 6 + demo/benchmark-clib/main.rs | 330 ++++++++++++++++++++++++++++++++ demo/benchmark-clib/run-demo.sh | 31 +++ 5 files changed, 416 insertions(+) create mode 100644 demo/benchmark-clib/README.md create mode 100644 demo/benchmark-clib/ljd.conf create mode 100644 demo/benchmark-clib/main.rs create mode 100755 demo/benchmark-clib/run-demo.sh diff --git a/demo/Cargo.toml b/demo/Cargo.toml index ede1802..60cebcc 100644 --- a/demo/Cargo.toml +++ b/demo/Cargo.toml @@ -4,8 +4,13 @@ version.workspace = true edition.workspace = true license.workspace = true +[[bin]] +name = "benchmark-clib" +path = "benchmark-clib/main.rs" + [dependencies] colored = "3" +liblogjet = { path = "../liblogjet" } logjet = { path = ".." } lz4_flex = { version = "0.11", default-features = false, features = ["std"] } opentelemetry-proto = { version = "0.31", features = ["gen-tonic", "logs", "metrics", "trace"] } diff --git a/demo/benchmark-clib/README.md b/demo/benchmark-clib/README.md new file mode 100644 index 0000000..ee4eb46 --- /dev/null +++ b/demo/benchmark-clib/README.md @@ -0,0 +1,44 @@ +# C-API Benchmark (Evidence) + +Decomposes the per-record cost of writing OTEL records through the `liblogjet` +C API (`log_record()` / `lj_logger_log`): the per-connection path is slow, and +this demo shows where the time goes. + +Reference: [`demo/cpp-shared-lib`](../cpp-shared-lib) + +## What it measures + +The driver times a single call in each of three phases and prints a table with +real numbers (mean, p50, p95, p99, min, max): + +1. **logjet file (`LogjetWriter::push`)** — appending one record straight to a + `.logjet` file. No network. Isolates the storage/format layer. +2. **backend OTLP/gRPC (per-connection)** — one `lj_logger_log()` send to `ljd`. + This is the slow path: a fresh connection per record. +3. **backend OTLP/gRPC (reuse)** — one `lj_logger_log_reuse()` send, reusing a + persistent gRPC channel (Ticket 1). + +This makes the finding explicit: the file write is cheap (µs); the +per-connection backend send is the expensive part (~ms), and connection reuse +brings it back down toward the file-write cost. + +The driver is Rust but calls the exported C ABI symbols of `liblogjet` — the +same functions a C/C++ caller exercises through the shared library — while also +linking the `logjet` crate directly for the file row. + +## Run + +From this directory: + +```bash +./run-demo.sh # 1000 records per phase (default) +./run-demo.sh 5000 # custom record count +``` + +The script builds `ljd`, `liblogjet`, and the driver, starts file-backed `ljd` +on `127.0.0.1:4317`, runs the benchmark, prints the table, and stops `ljd`. + +## Extending + +When new ABI lands (batching, async), add a phase that calls the new symbol and +a row to the table; the harness is structured for it. diff --git a/demo/benchmark-clib/ljd.conf b/demo/benchmark-clib/ljd.conf new file mode 100644 index 0000000..b6eb419 --- /dev/null +++ b/demo/benchmark-clib/ljd.conf @@ -0,0 +1,6 @@ +output: file +file.path: ./logs +file.size: 1048576 +file.name: benchmark-clib.logjet +ingest.protocol: otlp-grpc +ingest.listen: 127.0.0.1:4317 diff --git a/demo/benchmark-clib/main.rs b/demo/benchmark-clib/main.rs new file mode 100644 index 0000000..ad2abce --- /dev/null +++ b/demo/benchmark-clib/main.rs @@ -0,0 +1,330 @@ +//! Evidence benchmark for the liblogjet C API. +//! +//! Decomposes the per-record cost into: +//! 1. writing one record to a `.logjet` file (storage format, no network) +//! 2. sending one record to the OTEL backend via the C API (`lj_logger_log`) +//! 3. sending one record to the OTEL backend reusing the connection +//! (`lj_logger_log_reuse`) +//! +//! It reproduces the slow per-connection path and shows where the per-record +//! time goes. +//! +//! The "file" row links the `logjet` crate directly; the "backend" rows call +//! the exported C ABI symbols of `liblogjet` (the same code a C/C++ caller +//! exercises through the shared library). + +use std::ffi::{CStr, CString}; +use std::fs::File; +use std::io::{BufWriter, Write}; +use std::ptr; +use std::time::{Instant, SystemTime, UNIX_EPOCH}; + +use liblogjet::{LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_free, lj_logger_log, lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc}; +use logjet::{LogjetWriter, RecordType}; + +const LJ_ATTR_STRING: i32 = 0; +const SEVERITY_INFO: i32 = 9; +const TIMEOUT_MS: u64 = 2000; +const PAYLOAD_LEN: usize = 200; + +type LogFn = unsafe extern "C" fn(*mut lj_logger, *const LjLogRecord) -> bool; + +struct Stats { + count: usize, + total: f64, + mean: f64, + p50: f64, + p95: f64, + p99: f64, + min: f64, + max: f64, +} + +fn main() { + let mut args = std::env::args().skip(1); + let endpoint = args.next().unwrap_or_else(|| "127.0.0.1:4317".to_string()); + let count: usize = args.next().and_then(|value| value.parse().ok()).filter(|n| *n > 0).unwrap_or(1000); + let batch_size: usize = args.next().and_then(|value| value.parse().ok()).filter(|n| *n > 0).unwrap_or(100); + + println!("benchmark-clib: {count} records per phase, batch={batch_size}, endpoint {endpoint}\n"); + + let file_samples = match run_file_phase(count) { + Ok(samples) => samples, + Err(err) => { + eprintln!("logjet file phase failed: {err}"); + std::process::exit(1); + } + }; + + let endpoint_c = CString::new(endpoint.as_str()).expect("endpoint has interior NUL"); + let service_c = CString::new("benchmark-clib").expect("service name"); + let body_c = CString::new("benchmark log record body from benchmark-clib evidence run").expect("body"); + + let mut keepalive: Vec = Vec::new(); + let mut attrs: Vec = Vec::new(); + for (key, value) in [("appliance.kind", "benchmark"), ("character", "Bender"), ("location", "Planet Express")] { + let key_c = CString::new(key).expect("attr key"); + let value_c = CString::new(value).expect("attr value"); + attrs.push(LjAttribute { key: key_c.as_ptr(), value: value_c.as_ptr(), value_type: LJ_ATTR_STRING }); + keepalive.push(key_c); + keepalive.push(value_c); + } + + let mut record = LjLogRecord { + timestamp_unix_ns: 0, + severity_number: SEVERITY_INFO, + severity_text: ptr::null(), + body: body_c.as_ptr(), + attributes: attrs.as_ptr(), + attributes_len: attrs.len(), + event_name: ptr::null(), + service_name: ptr::null(), + scope_name: ptr::null(), + resource_attrs: ptr::null(), + resource_attrs_len: 0, + scope_attrs: ptr::null(), + scope_attrs_len: 0, + }; + + let per_connection = match unsafe { run_backend_phase(&endpoint_c, &service_c, &mut record, count, lj_logger_log) } { + Ok(result) => result, + Err(err) => { + eprintln!("per-connection backend phase failed: {err}"); + eprintln!("is ljd listening on {endpoint}? start it with run-demo.sh"); + std::process::exit(1); + } + }; + + let reuse = match unsafe { run_backend_phase(&endpoint_c, &service_c, &mut record, count, lj_logger_log_reuse) } { + Ok(result) => result, + Err(err) => { + eprintln!("reuse backend phase failed: {err}"); + std::process::exit(1); + } + }; + + let batch = match unsafe { run_batch_phase(&endpoint_c, &service_c, &record, count, batch_size) } { + Ok(result) => result, + Err(err) => { + eprintln!("batch backend phase failed: {err}"); + std::process::exit(1); + } + }; + + let file_stats = summarize(file_samples); + let per_connection_stats = summarize(per_connection.samples); + let reuse_cold = reuse.cold_first; + let reuse_stats = summarize(reuse.samples); + let raw_batch_mean = batch.raw_batch_mean; + let batch_stats = summarize(batch.samples); + let batch_label = format!("backend OTLP/gRPC (batch={batch_size})"); + + print_table(&[ + ("logjet file (LogjetWriter::push)", &file_stats), + ("backend OTLP/gRPC (per-connection)", &per_connection_stats), + ("backend OTLP/gRPC (reuse)", &reuse_stats), + (batch_label.as_str(), &batch_stats), + ]); + + println!(); + println!("note: batch row is per-record amortized; raw per-batch-call mean: {}", fmt_dur(raw_batch_mean)); + println!("reuse first/cold call (one-time connect): {}", fmt_dur(reuse_cold)); + if reuse_stats.mean > 0.0 { + println!("backend speedup (mean, per-connection -> reuse): {:.1}x", per_connection_stats.mean / reuse_stats.mean); + } + if batch_stats.mean > 0.0 { + println!("backend speedup (mean, per-connection -> batch): {:.1}x", per_connection_stats.mean / batch_stats.mean); + } +} + +fn run_file_phase(count: usize) -> std::io::Result> { + let path = std::env::temp_dir().join("logjet-benchmark-clib.logjet"); + let file = File::create(&path)?; + let mut writer = LogjetWriter::new(BufWriter::new(file)); + let payload = vec![0xABu8; PAYLOAD_LEN]; + let base_ts = 1_700_000_000_000_000_000u64; + + let mut samples = Vec::with_capacity(count); + for index in 0..count { + let seq = index as u64 + 1; + let ts = base_ts + index as u64 * 1_000; + let start = Instant::now(); + writer.push(RecordType::Logs, seq, ts, &payload).map_err(|err| std::io::Error::other(err.to_string()))?; + samples.push(start.elapsed().as_nanos()); + } + + let mut inner = writer.into_inner().map_err(|err| std::io::Error::other(err.to_string()))?; + inner.flush()?; + let _ = std::fs::remove_file(&path); + Ok(samples) +} + +struct BackendResult { + samples: Vec, + cold_first: f64, +} + +unsafe fn run_backend_phase(endpoint: &CStr, service: &CStr, record: &mut LjLogRecord, count: usize, log_fn: LogFn) -> Result { + let logger = unsafe { lj_logger_new_grpc(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; + if logger.is_null() { + return Err(last_error()); + } + + let mut samples = Vec::with_capacity(count); + let mut error: Option = None; + for _ in 0..count { + record.timestamp_unix_ns = now_unix_ns(); + let start = Instant::now(); + let ok = unsafe { log_fn(logger, record as *const LjLogRecord) }; + let elapsed = start.elapsed().as_nanos(); + if !ok { + error = Some(last_error()); + break; + } + samples.push(elapsed); + } + + unsafe { lj_logger_free(logger) }; + + if let Some(err) = error { + return Err(err); + } + + let cold_first = samples.first().copied().unwrap_or(0) as f64; + Ok(BackendResult { samples, cold_first }) +} + +struct BatchResult { + samples: Vec, + raw_batch_mean: f64, +} + +fn clone_record(template: &LjLogRecord) -> LjLogRecord { + LjLogRecord { + timestamp_unix_ns: template.timestamp_unix_ns, + severity_number: template.severity_number, + severity_text: template.severity_text, + body: template.body, + attributes: template.attributes, + attributes_len: template.attributes_len, + event_name: template.event_name, + service_name: template.service_name, + scope_name: template.scope_name, + resource_attrs: template.resource_attrs, + resource_attrs_len: template.resource_attrs_len, + scope_attrs: template.scope_attrs, + scope_attrs_len: template.scope_attrs_len, + } +} + +unsafe fn run_batch_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, batch_size: usize) -> Result { + let logger = unsafe { lj_logger_new_grpc(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; + if logger.is_null() { + return Err(last_error()); + } + + let mut batch: Vec = (0..batch_size).map(|_| clone_record(template)).collect(); + let mut samples = Vec::with_capacity(count); + let mut total_batch_ns: u128 = 0; + let mut batch_calls: u128 = 0; + let mut sent = 0; + let mut error: Option = None; + + while sent < count { + let this = batch_size.min(count - sent); + let now = now_unix_ns(); + for entry in batch[..this].iter_mut() { + entry.timestamp_unix_ns = now; + } + let start = Instant::now(); + let ok = unsafe { lj_logger_log_batch(logger, batch.as_ptr(), this) }; + let elapsed = start.elapsed().as_nanos(); + if !ok { + error = Some(last_error()); + break; + } + total_batch_ns += elapsed; + batch_calls += 1; + let per_record = elapsed / this as u128; + for _ in 0..this { + samples.push(per_record); + } + sent += this; + } + + unsafe { lj_logger_free(logger) }; + + if let Some(err) = error { + return Err(err); + } + + let raw_batch_mean = if batch_calls > 0 { total_batch_ns as f64 / batch_calls as f64 } else { 0.0 }; + Ok(BatchResult { samples, raw_batch_mean }) +} + +fn last_error() -> String { + let ptr = lj_error_message(); + if ptr.is_null() { + return "unknown error".to_string(); + } + let message = unsafe { CStr::from_ptr(ptr) }.to_string_lossy().into_owned(); + if message.is_empty() { "unknown error".to_string() } else { message } +} + +fn now_unix_ns() -> u64 { + SystemTime::now().duration_since(UNIX_EPOCH).unwrap_or_default().as_nanos() as u64 +} + +fn summarize(mut samples: Vec) -> Stats { + assert!(!samples.is_empty(), "no samples collected"); + samples.sort_unstable(); + let count = samples.len(); + let total: u128 = samples.iter().sum(); + let percentile = |pct: f64| { + let rank = ((pct / 100.0) * count as f64).ceil() as usize; + let index = rank.saturating_sub(1).min(count - 1); + samples[index] as f64 + }; + Stats { + count, + total: total as f64, + mean: total as f64 / count as f64, + p50: percentile(50.0), + p95: percentile(95.0), + p99: percentile(99.0), + min: samples[0] as f64, + max: samples[count - 1] as f64, + } +} + +fn fmt_dur(ns: f64) -> String { + if ns >= 1e9 { + format!("{:.2} s", ns / 1e9) + } else if ns >= 1e6 { + format!("{:.2} ms", ns / 1e6) + } else if ns >= 1e3 { + format!("{:.2} us", ns / 1e3) + } else { + format!("{ns:.0} ns") + } +} + +fn print_table(rows: &[(&str, &Stats)]) { + println!("{:<36} {:>7} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11}", "path", "calls", "total", "mean", "p50", "p95", "p99", "min", "max"); + println!("{}", "-".repeat(36 + 7 + 11 * 7 + 8)); + for (name, stats) in rows { + println!( + "{:<36} {:>7} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11}", + name, + stats.count, + fmt_dur(stats.total), + fmt_dur(stats.mean), + fmt_dur(stats.p50), + fmt_dur(stats.p95), + fmt_dur(stats.p99), + fmt_dur(stats.min), + fmt_dur(stats.max), + ); + } + let _ = std::io::stdout().flush(); +} diff --git a/demo/benchmark-clib/run-demo.sh b/demo/benchmark-clib/run-demo.sh new file mode 100755 index 0000000..a7f7e34 --- /dev/null +++ b/demo/benchmark-clib/run-demo.sh @@ -0,0 +1,31 @@ +#!/bin/sh +set -eu + +SCRIPT_DIR=$(CDPATH= cd -- "$(dirname -- "$0")" && pwd) +ROOT_DIR=$(CDPATH= cd -- "$SCRIPT_DIR/../.." && pwd) +TARGET_DIR="$ROOT_DIR/target/debug" +LJD="$TARGET_DIR/ljd" +BENCH="$TARGET_DIR/benchmark-clib" +CONFIG="$SCRIPT_DIR/ljd.conf" +ENDPOINT="127.0.0.1:4317" +COUNT="${1:-1000}" + +echo "building ljd, liblogjet, and the benchmark driver" +cargo build -p ljd -p liblogjet -p otlp-demo --bin benchmark-clib + +mkdir -p "$SCRIPT_DIR/logs" + +echo "starting ljd with file-backed OTLP/gRPC ingest on $ENDPOINT" +(cd "$SCRIPT_DIR" && "$LJD" --config "$CONFIG" serve) & +LJD_PID=$! + +cleanup() { + kill "${LJD_PID:-}" 2>/dev/null || true +} +trap cleanup EXIT INT TERM + +sleep 1 + +echo "running benchmark ($COUNT records per phase)" +echo +"$BENCH" "$ENDPOINT" "$COUNT" From 72e6245be7f8e88153187ceb3eb89fbbe111057e Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 13:34:32 +0200 Subject: [PATCH 04/21] Update UT --- liblogjet/tests/unit/batch_ut.rs | 123 +++++++++++++++++++++++++++++++ 1 file changed, 123 insertions(+) create mode 100644 liblogjet/tests/unit/batch_ut.rs diff --git a/liblogjet/tests/unit/batch_ut.rs b/liblogjet/tests/unit/batch_ut.rs new file mode 100644 index 0000000..b7b2632 --- /dev/null +++ b/liblogjet/tests/unit/batch_ut.rs @@ -0,0 +1,123 @@ +use std::ffi::{CStr, CString}; +use std::ptr; +use std::time::Duration; + +use opentelemetry_proto::tonic::common::v1::any_value::Value; + +use super::{Backend, HttpEndpoint, LjLogRecord, Logger, build_batch_request}; + +fn test_logger(service: &str) -> Logger { + Logger { + backend: Backend::Http(HttpEndpoint { + authority: "127.0.0.1:4318".to_string(), + host_header: "127.0.0.1:4318".to_string(), + path: "/v1/logs".to_string(), + }), + service_name: service.to_string(), + timeout: Duration::from_millis(1000), + } +} + +fn record(ts: u64, body: &CStr, service: Option<&CStr>, scope: Option<&CStr>) -> LjLogRecord { + LjLogRecord { + timestamp_unix_ns: ts, + severity_number: 9, + severity_text: ptr::null(), + body: body.as_ptr(), + attributes: ptr::null(), + attributes_len: 0, + event_name: ptr::null(), + service_name: service.map_or(ptr::null(), CStr::as_ptr), + scope_name: scope.map_or(ptr::null(), CStr::as_ptr), + resource_attrs: ptr::null(), + resource_attrs_len: 0, + scope_attrs: ptr::null(), + scope_attrs_len: 0, + } +} + +#[test] +fn identical_records_collapse_into_one_scope() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let records = vec![record(1, &body, None, None), record(2, &body, None, None), record(3, &body, None, None)]; + + let request = build_batch_request(&logger, &records).expect("batch request"); + + assert_eq!(request.resource_logs.len(), 1); + assert_eq!(request.resource_logs[0].scope_logs.len(), 1); + assert_eq!(request.resource_logs[0].scope_logs[0].log_records.len(), 3); +} + +#[test] +fn differing_scope_names_split_scopes() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let scope_a = CString::new("scope-a").unwrap(); + let scope_b = CString::new("scope-b").unwrap(); + let records = vec![record(1, &body, None, Some(&scope_a)), record(2, &body, None, Some(&scope_b))]; + + let request = build_batch_request(&logger, &records).expect("batch request"); + + assert_eq!(request.resource_logs.len(), 1); + assert_eq!(request.resource_logs[0].scope_logs.len(), 2); +} + +#[test] +fn differing_service_names_split_resources() { + let logger = test_logger("default-svc"); + let body = CString::new("hello").unwrap(); + let service_a = CString::new("svc-a").unwrap(); + let service_b = CString::new("svc-b").unwrap(); + let records = vec![record(1, &body, Some(&service_a), None), record(2, &body, Some(&service_b), None)]; + + let request = build_batch_request(&logger, &records).expect("batch request"); + + assert_eq!(request.resource_logs.len(), 2); +} + +#[test] +fn injects_service_name_into_resource() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let records = vec![record(1, &body, None, None)]; + + let request = build_batch_request(&logger, &records).expect("batch request"); + + let attributes = &request.resource_logs[0].resource.as_ref().expect("resource").attributes; + let service = attributes.iter().find(|kv| kv.key == "service.name").expect("service.name present"); + match service.value.as_ref().and_then(|value| value.value.as_ref()) { + Some(Value::StringValue(name)) => assert_eq!(name, "svc"), + other => panic!("unexpected service.name value: {other:?}"), + } +} + +#[test] +fn empty_slice_yields_no_resource_logs() { + let logger = test_logger("svc"); + let request = build_batch_request(&logger, &[]).expect("batch request"); + assert!(request.resource_logs.is_empty()); +} + +#[test] +fn missing_body_is_an_error() { + let logger = test_logger("svc"); + let mut bad = record(1, c"x", None, None); + bad.body = ptr::null(); + let records = vec![bad]; + + assert!(build_batch_request(&logger, &records).is_err()); +} + +#[test] +fn timestamps_are_preserved_per_record() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let records = vec![record(111, &body, None, None), record(222, &body, None, None)]; + + let request = build_batch_request(&logger, &records).expect("batch request"); + + let logs = &request.resource_logs[0].scope_logs[0].log_records; + assert_eq!(logs[0].time_unix_nano, 111); + assert_eq!(logs[1].time_unix_nano, 222); +} From 6b4e6aa43cf084a7bc3aacdf3b9ccbb2be602696 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 13:59:42 +0200 Subject: [PATCH 05/21] Add batch size setting for the demo --- demo/benchmark-clib/README.md | 25 +++++++++++++++++-------- demo/benchmark-clib/run-demo.sh | 5 +++-- 2 files changed, 20 insertions(+), 10 deletions(-) diff --git a/demo/benchmark-clib/README.md b/demo/benchmark-clib/README.md index ee4eb46..6ca93d6 100644 --- a/demo/benchmark-clib/README.md +++ b/demo/benchmark-clib/README.md @@ -8,8 +8,8 @@ Reference: [`demo/cpp-shared-lib`](../cpp-shared-lib) ## What it measures -The driver times a single call in each of three phases and prints a table with -real numbers (mean, p50, p95, p99, min, max): +The driver times each call across four phases and prints a table with real +numbers (mean, p50, p95, p99, min, max): 1. **logjet file (`LogjetWriter::push`)** — appending one record straight to a `.logjet` file. No network. Isolates the storage/format layer. @@ -17,10 +17,12 @@ real numbers (mean, p50, p95, p99, min, max): This is the slow path: a fresh connection per record. 3. **backend OTLP/gRPC (reuse)** — one `lj_logger_log_reuse()` send, reusing a persistent gRPC channel (Ticket 1). +4. **backend OTLP/gRPC (batch=N)** — `lj_logger_log_batch()` sending N records in + one request over the reused channel (Ticket 2). Reported per-record amortized. This makes the finding explicit: the file write is cheap (µs); the -per-connection backend send is the expensive part (~ms), and connection reuse -brings it back down toward the file-write cost. +per-connection backend send is the expensive part (~ms); connection reuse helps, +and batching brings the per-record cost back down toward the file-write cost. The driver is Rust but calls the exported C ABI symbols of `liblogjet` — the same functions a C/C++ caller exercises through the shared library — while also @@ -31,14 +33,21 @@ linking the `logjet` crate directly for the file row. From this directory: ```bash -./run-demo.sh # 1000 records per phase (default) -./run-demo.sh 5000 # custom record count +./run-demo.sh # 1000 records per phase, batch=100 (defaults) +./run-demo.sh 5000 # custom record count +./run-demo.sh 1000 50 # low-mem batch size +./run-demo.sh 1000 1000 # hi-mem batch size ``` +Arguments are `./run-demo.sh [count] [batch_size]`. The batch size is the number +of records sent per `lj_logger_log_batch()` call (the caller controls it); change +it to see how the per-record amortized cost in the `batch=N` row moves. + The script builds `ljd`, `liblogjet`, and the driver, starts file-backed `ljd` on `127.0.0.1:4317`, runs the benchmark, prints the table, and stops `ljd`. ## Extending -When new ABI lands (batching, async), add a phase that calls the new symbol and -a row to the table; the harness is structured for it. +Reuse (Ticket 1) and batching (Ticket 2) rows are in place. When further ABI +lands (e.g. async, Ticket 3), add a phase that calls the new symbol and a row to +the table; the harness is structured for it. diff --git a/demo/benchmark-clib/run-demo.sh b/demo/benchmark-clib/run-demo.sh index a7f7e34..435b76f 100755 --- a/demo/benchmark-clib/run-demo.sh +++ b/demo/benchmark-clib/run-demo.sh @@ -9,6 +9,7 @@ BENCH="$TARGET_DIR/benchmark-clib" CONFIG="$SCRIPT_DIR/ljd.conf" ENDPOINT="127.0.0.1:4317" COUNT="${1:-1000}" +BATCH_SIZE="${2:-100}" echo "building ljd, liblogjet, and the benchmark driver" cargo build -p ljd -p liblogjet -p otlp-demo --bin benchmark-clib @@ -26,6 +27,6 @@ trap cleanup EXIT INT TERM sleep 1 -echo "running benchmark ($COUNT records per phase)" +echo "running benchmark ($COUNT records per phase, batch=$BATCH_SIZE)" echo -"$BENCH" "$ENDPOINT" "$COUNT" +"$BENCH" "$ENDPOINT" "$COUNT" "$BATCH_SIZE" From 41b2dd45acc16b85624df2341480eff08023a6d2 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 14:35:22 +0200 Subject: [PATCH 06/21] Add backpressure modes --- liblogjet/include/liblogjet.h | 12 ++ liblogjet/src/lib.rs | 334 +++++++++++++++++++++++++++++++--- 2 files changed, 321 insertions(+), 25 deletions(-) diff --git a/liblogjet/include/liblogjet.h b/liblogjet/include/liblogjet.h index 5535c0c..76a311f 100644 --- a/liblogjet/include/liblogjet.h +++ b/liblogjet/include/liblogjet.h @@ -20,6 +20,11 @@ extern "C" { #define LJ_ATTR_INT 1 #define LJ_ATTR_ARRAY 2 +// Async backpressure models (lj_logger_set_backpressure). +#define LJ_BACKPRESSURE_UNBOUNDED 0 +#define LJ_BACKPRESSURE_DROP 1 +#define LJ_BACKPRESSURE_BLOCK 2 + // Ingest plugin signal bitmask (in descriptor reserved[0], ABI >= 1.1). #define LJ_INGEST_SIGNAL_LOGS (1u << 0) #define LJ_INGEST_SIGNAL_METRICS (1u << 1) @@ -158,6 +163,13 @@ lj_logger *lj_logger_new_grpc(const char *endpoint, const char *service_name, ui bool lj_logger_log(lj_logger *logger, const lj_log_record *record); bool lj_logger_log_reuse(lj_logger *logger, const lj_log_record *record); bool lj_logger_log_batch(lj_logger *logger, const lj_log_record *records, size_t len); +bool lj_logger_log_async(lj_logger *logger, const lj_log_record *record); +bool lj_logger_log_batch_async(lj_logger *logger, const lj_log_record *records, size_t len); +bool lj_logger_set_backpressure(lj_logger *logger, int32_t model, size_t capacity); +bool lj_logger_flush(lj_logger *logger, uint64_t timeout_ms); +uint64_t lj_logger_async_errors(lj_logger *logger); +uint64_t lj_logger_async_dropped(lj_logger *logger); +uint64_t lj_logger_async_inflight(lj_logger *logger); void lj_logger_free(lj_logger *logger); lj_ingest_plugin *lj_ingest_create(void); diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index b3bd0fb..3e64024 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -6,7 +6,8 @@ use std::cell::RefCell; use std::ffi::{CStr, CString, c_char}; use std::io::{Read, Write}; use std::net::{Shutdown, TcpStream}; -use std::sync::Mutex; +use std::sync::atomic::{AtomicU64, Ordering}; +use std::sync::{Arc, Mutex}; use std::time::Duration; use opentelemetry_proto::tonic::collector::logs::v1::{ExportLogsServiceRequest, logs_service_client::LogsServiceClient}; @@ -16,12 +17,17 @@ use opentelemetry_proto::tonic::logs::v1::{LogRecord, ResourceLogs, ScopeLogs}; use opentelemetry_proto::tonic::resource::v1::Resource; use prost::Message; use tokio::runtime::{Builder, Runtime}; +use tokio::sync::{Mutex as TokioMutex, Notify, OwnedSemaphorePermit, Semaphore}; use tonic::Request; use tonic::transport::{Channel, Endpoint}; const LJ_ATTR_STRING: i32 = 0; const LJ_ATTR_INT: i32 = 1; const LJ_ATTR_ARRAY: i32 = 2; +const LJ_BACKPRESSURE_UNBOUNDED: i32 = 0; +const LJ_BACKPRESSURE_DROP: i32 = 1; +const LJ_BACKPRESSURE_BLOCK: i32 = 2; +const DEFAULT_BACKPRESSURE_CAPACITY: usize = 1024; const DEFAULT_SCOPE_NAME: &str = "liblogjet"; const VERSION: &[u8] = concat!(env!("CARGO_PKG_VERSION"), "\0").as_bytes(); @@ -96,9 +102,23 @@ struct HttpEndpoint { } struct GrpcClient { + runtime: Runtime, + shared: Arc, +} + +struct GrpcShared { endpoint: String, - runtime: Mutex, - channel: Mutex>, + channel: TokioMutex>, + backpressure: Mutex, + inflight: AtomicU64, + async_errors: AtomicU64, + async_dropped: AtomicU64, + idle: Notify, +} + +struct Backpressure { + model: i32, + semaphore: Arc, } /// Returns the library version string. @@ -149,7 +169,7 @@ pub unsafe extern "C" fn lj_logger_new_grpc(endpoint: *const c_char, service_nam #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_log(logger: *mut lj_logger, record: *const LjLogRecord) -> bool { clear_last_error(); - let logger = match unsafe { logger.as_mut() } { + let logger = match unsafe { logger.as_ref() } { Some(logger) => logger, None => { set_last_error("logger is null"); @@ -186,7 +206,7 @@ pub unsafe extern "C" fn lj_logger_log(logger: *mut lj_logger, record: *const Lj #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_log_reuse(logger: *mut lj_logger, record: *const LjLogRecord) -> bool { clear_last_error(); - let logger = match unsafe { logger.as_mut() } { + let logger = match unsafe { logger.as_ref() } { Some(logger) => logger, None => { set_last_error("logger is null"); @@ -226,7 +246,7 @@ pub unsafe extern "C" fn lj_logger_log_reuse(logger: *mut lj_logger, record: *co #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_log_batch(logger: *mut lj_logger, records: *const LjLogRecord, len: usize) -> bool { clear_last_error(); - let logger = match unsafe { logger.as_mut() } { + let logger = match unsafe { logger.as_ref() } { Some(logger) => logger, None => { set_last_error("logger is null"); @@ -246,6 +266,196 @@ pub unsafe extern "C" fn lj_logger_log_batch(logger: *mut lj_logger, records: *c } } +/// Sends one log record without blocking, handing the send to a background +/// runtime and returning immediately. +/// +/// gRPC only. Returns `true` if the record was validated and enqueued; `false` +/// (with `lj_error_message` set) only on immediate validation errors. Network +/// failures occur later and are counted by `lj_logger_async_errors`; records +/// dropped by backpressure are counted by `lj_logger_async_dropped`. +/// +/// # Safety +/// +/// `logger` must be a valid pointer returned by `lj_logger_new_grpc`. `record` +/// must point to a valid `LjLogRecord` for the duration of the call. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_log_async(logger: *mut lj_logger, record: *const LjLogRecord) -> bool { + clear_last_error(); + let logger = match unsafe { logger.as_ref() } { + Some(logger) => logger, + None => { + set_last_error("logger is null"); + return false; + } + }; + let record = match unsafe { record.as_ref() } { + Some(record) => record, + None => { + set_last_error("record is null"); + return false; + } + }; + match build_request(&logger.inner, record).and_then(|request| send_request_async(&logger.inner, request)) { + Ok(()) => true, + Err(err) => { + set_last_error(err); + false + } + } +} + +/// Sends a batch of records without blocking (gRPC only). A `len` of `0` (or a +/// null `records` pointer) is a successful no-op. +/// +/// # Safety +/// +/// `logger` must be a valid pointer returned by `lj_logger_new_grpc`. When +/// `len > 0`, `records` must point to `len` valid `LjLogRecord` values for the +/// duration of the call. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_log_batch_async(logger: *mut lj_logger, records: *const LjLogRecord, len: usize) -> bool { + clear_last_error(); + let logger = match unsafe { logger.as_ref() } { + Some(logger) => logger, + None => { + set_last_error("logger is null"); + return false; + } + }; + if len == 0 || records.is_null() { + return true; + } + let records = unsafe { std::slice::from_raw_parts(records, len) }; + match build_batch_request(&logger.inner, records).and_then(|request| send_request_async(&logger.inner, request)) { + Ok(()) => true, + Err(err) => { + set_last_error(err); + false + } + } +} + +/// Configures the async backpressure policy for a gRPC logger. +/// +/// `model` is one of `LJ_BACKPRESSURE_UNBOUNDED`, `LJ_BACKPRESSURE_DROP`, or +/// `LJ_BACKPRESSURE_BLOCK`. `capacity` is the maximum number of in-flight async +/// sends for the bounded models (ignored for unbounded). Should be called +/// before the first async send. Returns `false` (with `lj_error_message`) on +/// invalid input or for non-gRPC loggers. +/// +/// # Safety +/// +/// `logger` must be a valid pointer returned by `lj_logger_new_grpc`. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_set_backpressure(logger: *mut lj_logger, model: i32, capacity: usize) -> bool { + clear_last_error(); + let logger = match unsafe { logger.as_ref() } { + Some(logger) => logger, + None => { + set_last_error("logger is null"); + return false; + } + }; + let client = match &logger.inner.backend { + Backend::Grpc(client) => client, + Backend::Http(_) => { + set_last_error("backpressure applies to gRPC loggers only"); + return false; + } + }; + if model != LJ_BACKPRESSURE_UNBOUNDED && model != LJ_BACKPRESSURE_DROP && model != LJ_BACKPRESSURE_BLOCK { + set_last_error("invalid backpressure model"); + return false; + } + let capacity = if model == LJ_BACKPRESSURE_UNBOUNDED { + 1 + } else if capacity == 0 { + set_last_error("capacity must be >= 1 for bounded backpressure"); + return false; + } else { + capacity + }; + match client.shared.backpressure.lock() { + Ok(mut cfg) => { + cfg.model = model; + cfg.semaphore = Arc::new(Semaphore::new(capacity)); + true + } + Err(_) => { + set_last_error("backpressure lock poisoned"); + false + } + } +} + +/// Blocks until all in-flight async sends complete or `timeout_ms` elapses. +/// +/// Returns `true` if fully drained, `false` on timeout. HTTP loggers (which have +/// no async queue) always return `true`. +/// +/// # Safety +/// +/// `logger` must be a valid pointer returned by this library. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_flush(logger: *mut lj_logger, timeout_ms: u64) -> bool { + let logger = match unsafe { logger.as_ref() } { + Some(logger) => logger, + None => return false, + }; + match &logger.inner.backend { + Backend::Grpc(client) => flush_grpc(client, Duration::from_millis(timeout_ms)), + Backend::Http(_) => true, + } +} + +/// Returns the number of async sends that failed on the network. +/// +/// # Safety +/// +/// `logger` must be null or a valid pointer returned by this library. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_async_errors(logger: *mut lj_logger) -> u64 { + match unsafe { logger.as_ref() } { + Some(logger) => match &logger.inner.backend { + Backend::Grpc(client) => client.shared.async_errors.load(Ordering::Relaxed), + Backend::Http(_) => 0, + }, + None => 0, + } +} + +/// Returns the number of records dropped by bounded backpressure. +/// +/// # Safety +/// +/// `logger` must be null or a valid pointer returned by this library. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_async_dropped(logger: *mut lj_logger) -> u64 { + match unsafe { logger.as_ref() } { + Some(logger) => match &logger.inner.backend { + Backend::Grpc(client) => client.shared.async_dropped.load(Ordering::Relaxed), + Backend::Http(_) => 0, + }, + None => 0, + } +} + +/// Returns the number of async sends currently in flight. +/// +/// # Safety +/// +/// `logger` must be null or a valid pointer returned by this library. +#[unsafe(no_mangle)] +pub unsafe extern "C" fn lj_logger_async_inflight(logger: *mut lj_logger) -> u64 { + match unsafe { logger.as_ref() } { + Some(logger) => match &logger.inner.backend { + Backend::Grpc(client) => client.shared.inflight.load(Ordering::SeqCst), + Backend::Http(_) => 0, + }, + None => 0, + } +} + /// Frees a logger created by one of the constructors. Accepts null. /// /// # Safety @@ -257,7 +467,10 @@ pub unsafe extern "C" fn lj_logger_free(logger: *mut lj_logger) { if logger.is_null() { return; } - let _ = unsafe { Box::from_raw(logger) }; + let boxed = unsafe { Box::from_raw(logger) }; + if let Backend::Grpc(client) = &boxed.inner.backend { + let _ = flush_grpc(client, boxed.inner.timeout); + } } enum BackendKind { @@ -283,7 +496,19 @@ unsafe fn new_logger_impl(endpoint: *const c_char, service_name: *const c_char, let backend = match kind { BackendKind::Http => Backend::Http(parse_http_endpoint(&endpoint)?), BackendKind::Grpc => { - Backend::Grpc(GrpcClient { endpoint: normalise_grpc_endpoint(&endpoint), runtime: Mutex::new(grpc_runtime()?), channel: Mutex::new(None) }) + let shared = Arc::new(GrpcShared { + endpoint: normalise_grpc_endpoint(&endpoint), + channel: TokioMutex::new(None), + backpressure: Mutex::new(Backpressure { + model: LJ_BACKPRESSURE_DROP, + semaphore: Arc::new(Semaphore::new(DEFAULT_BACKPRESSURE_CAPACITY)), + }), + inflight: AtomicU64::new(0), + async_errors: AtomicU64::new(0), + async_dropped: AtomicU64::new(0), + idle: Notify::new(), + }); + Backend::Grpc(GrpcClient { runtime: grpc_runtime()?, shared }) } }; Ok(Logger { backend, service_name, timeout }) @@ -468,44 +693,103 @@ fn key_value(key: impl Into, value: AnyValue) -> KeyValue { fn send_request(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { match &logger.backend { Backend::Http(endpoint) => post_otlp_http(endpoint, logger.timeout, &request).map_err(|err| err.to_string()), - Backend::Grpc(client) => client - .runtime - .lock() - .map_err(|_| "gRPC runtime lock poisoned".to_string())? - .block_on(send_otlp_grpc(client.endpoint.clone(), logger.timeout, request)) - .map_err(|err| err.to_string()), + Backend::Grpc(client) => client.runtime.block_on(send_otlp_grpc(client.shared.endpoint.clone(), logger.timeout, request)).map_err(|err| err.to_string()), } } fn send_request_reuse(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { match &logger.backend { Backend::Http(endpoint) => post_otlp_http(endpoint, logger.timeout, &request).map_err(|err| err.to_string()), - Backend::Grpc(client) => send_otlp_grpc_pooled(client, logger.timeout, request), + Backend::Grpc(client) => client.runtime.block_on(send_pooled_async(client.shared.clone(), logger.timeout, request)), + } +} + +fn send_request_async(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { + match &logger.backend { + Backend::Http(_) => Err("async send is not supported for HTTP loggers yet".to_string()), + Backend::Grpc(client) => enqueue_async_grpc(client, logger.timeout, request), } } -fn send_otlp_grpc_pooled(client: &GrpcClient, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { - let runtime = client.runtime.lock().map_err(|_| "gRPC runtime lock poisoned".to_string())?; +fn enqueue_async_grpc(client: &GrpcClient, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { + let (model, semaphore) = { + let cfg = client.shared.backpressure.lock().map_err(|_| "backpressure lock poisoned".to_string())?; + (cfg.model, cfg.semaphore.clone()) + }; + match model { + LJ_BACKPRESSURE_UNBOUNDED => spawn_send(client, timeout, request, None), + LJ_BACKPRESSURE_DROP => match semaphore.try_acquire_owned() { + Ok(permit) => spawn_send(client, timeout, request, Some(permit)), + Err(_) => { + client.shared.async_dropped.fetch_add(1, Ordering::Relaxed); + } + }, + LJ_BACKPRESSURE_BLOCK => { + let permit = client.runtime.block_on(semaphore.acquire_owned()).map_err(|err| err.to_string())?; + spawn_send(client, timeout, request, Some(permit)); + } + other => return Err(format!("invalid backpressure model {other}")), + } + Ok(()) +} + +fn spawn_send(client: &GrpcClient, timeout: Duration, request: ExportLogsServiceRequest, permit: Option) { + let shared = client.shared.clone(); + shared.inflight.fetch_add(1, Ordering::SeqCst); + client.runtime.spawn(async move { + let _permit = permit; + if send_pooled_async(shared.clone(), timeout, request).await.is_err() { + shared.async_errors.fetch_add(1, Ordering::Relaxed); + } + if shared.inflight.fetch_sub(1, Ordering::SeqCst) == 1 { + shared.idle.notify_waiters(); + } + }); +} + +fn flush_grpc(client: &GrpcClient, timeout: Duration) -> bool { + client.runtime.block_on(async { + let deadline = tokio::time::Instant::now() + timeout; + loop { + if client.shared.inflight.load(Ordering::SeqCst) == 0 { + return true; + } + let notified = client.shared.idle.notified(); + if client.shared.inflight.load(Ordering::SeqCst) == 0 { + return true; + } + let now = tokio::time::Instant::now(); + if now >= deadline { + return false; + } + if tokio::time::timeout(deadline - now, notified).await.is_err() { + return client.shared.inflight.load(Ordering::SeqCst) == 0; + } + } + }) +} +async fn send_pooled_async(shared: Arc, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { + // Connect-once: hold the lock across connect so a concurrent burst opens a + // single connection; release it before export so sends run concurrently over + // the shared multiplexed channel. let channel = { - let mut guard = client.channel.lock().map_err(|_| "gRPC channel lock poisoned".to_string())?; + let mut guard = shared.channel.lock().await; match guard.as_ref() { Some(channel) => channel.clone(), None => { - let channel = runtime.block_on(connect_channel(&client.endpoint, timeout)).map_err(|err| err.to_string())?; + let channel = connect_channel(&shared.endpoint, timeout).await.map_err(|err| err.to_string())?; *guard = Some(channel.clone()); channel } } }; - let result = runtime.block_on(export_on_channel(channel, request)); - if result.is_err() - && let Ok(mut guard) = client.channel.lock() - { - *guard = None; + let result = export_on_channel(channel, request).await.map_err(|err| err.to_string()); + if result.is_err() { + *shared.channel.lock().await = None; } - result.map_err(|err| err.to_string()) + result } async fn connect_channel(endpoint: &str, timeout: Duration) -> Result> { From 5a2f2f7c9321dddc71d8acc7f3fe68e8f6a6abfb Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 14:35:33 +0200 Subject: [PATCH 07/21] Update benchmark demo --- demo/benchmark-clib/main.rs | 63 ++++++++++++++++++++++++++++++++++++- 1 file changed, 62 insertions(+), 1 deletion(-) diff --git a/demo/benchmark-clib/main.rs b/demo/benchmark-clib/main.rs index ad2abce..42c62ef 100644 --- a/demo/benchmark-clib/main.rs +++ b/demo/benchmark-clib/main.rs @@ -19,7 +19,10 @@ use std::io::{BufWriter, Write}; use std::ptr; use std::time::{Instant, SystemTime, UNIX_EPOCH}; -use liblogjet::{LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_free, lj_logger_log, lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc}; +use liblogjet::{ + LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, lj_logger_log, lj_logger_log_async, + lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, +}; use logjet::{LogjetWriter, RecordType}; const LJ_ATTR_STRING: i32 = 0; @@ -111,6 +114,14 @@ fn main() { } }; + let async_phase = match unsafe { run_async_phase(&endpoint_c, &service_c, &record, count) } { + Ok(result) => result, + Err(err) => { + eprintln!("async backend phase failed: {err}"); + std::process::exit(1); + } + }; + let file_stats = summarize(file_samples); let per_connection_stats = summarize(per_connection.samples); let reuse_cold = reuse.cold_first; @@ -118,16 +129,24 @@ fn main() { let raw_batch_mean = batch.raw_batch_mean; let batch_stats = summarize(batch.samples); let batch_label = format!("backend OTLP/gRPC (batch={batch_size})"); + let async_stats = summarize(async_phase.samples); print_table(&[ ("logjet file (LogjetWriter::push)", &file_stats), ("backend OTLP/gRPC (per-connection)", &per_connection_stats), ("backend OTLP/gRPC (reuse)", &reuse_stats), (batch_label.as_str(), &batch_stats), + ("backend OTLP/gRPC (async enqueue)", &async_stats), ]); println!(); println!("note: batch row is per-record amortized; raw per-batch-call mean: {}", fmt_dur(raw_batch_mean)); + println!( + "note: async row is the caller-thread enqueue cost (fire-and-forget); flush: {}, errors: {}, dropped: {}", + fmt_dur(async_phase.flush_ns), + async_phase.errors, + async_phase.dropped, + ); println!("reuse first/cold call (one-time connect): {}", fmt_dur(reuse_cold)); if reuse_stats.mean > 0.0 { println!("backend speedup (mean, per-connection -> reuse): {:.1}x", per_connection_stats.mean / reuse_stats.mean); @@ -135,6 +154,9 @@ fn main() { if batch_stats.mean > 0.0 { println!("backend speedup (mean, per-connection -> batch): {:.1}x", per_connection_stats.mean / batch_stats.mean); } + if async_stats.mean > 0.0 { + println!("backend speedup (mean, per-connection -> async enqueue): {:.1}x", per_connection_stats.mean / async_stats.mean); + } } fn run_file_phase(count: usize) -> std::io::Result> { @@ -262,6 +284,45 @@ unsafe fn run_batch_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecor Ok(BatchResult { samples, raw_batch_mean }) } +struct AsyncResult { + samples: Vec, + flush_ns: f64, + errors: u64, + dropped: u64, +} + +unsafe fn run_async_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize) -> Result { + let logger = unsafe { lj_logger_new_grpc(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; + if logger.is_null() { + return Err(last_error()); + } + + let mut record = clone_record(template); + let mut samples = Vec::with_capacity(count); + for _ in 0..count { + record.timestamp_unix_ns = now_unix_ns(); + let start = Instant::now(); + let ok = unsafe { lj_logger_log_async(logger, &record as *const LjLogRecord) }; + let elapsed = start.elapsed().as_nanos(); + if !ok { + let err = last_error(); + unsafe { lj_logger_free(logger) }; + return Err(err); + } + samples.push(elapsed); + } + + let flush_start = Instant::now(); + unsafe { lj_logger_flush(logger, 60_000) }; + let flush_ns = flush_start.elapsed().as_nanos() as f64; + + let errors = unsafe { lj_logger_async_errors(logger) }; + let dropped = unsafe { lj_logger_async_dropped(logger) }; + + unsafe { lj_logger_free(logger) }; + Ok(AsyncResult { samples, flush_ns, errors, dropped }) +} + fn last_error() -> String { let ptr = lj_error_message(); if ptr.is_null() { From 4817cfe816ba9fc9b6bb85f48bb61e49ed0af24c Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 14:35:53 +0200 Subject: [PATCH 08/21] Update docs on async backpressure --- demo/benchmark-clib/README.md | 29 ++++++++++++++++++++++++----- 1 file changed, 24 insertions(+), 5 deletions(-) diff --git a/demo/benchmark-clib/README.md b/demo/benchmark-clib/README.md index 6ca93d6..72b110a 100644 --- a/demo/benchmark-clib/README.md +++ b/demo/benchmark-clib/README.md @@ -8,7 +8,7 @@ Reference: [`demo/cpp-shared-lib`](../cpp-shared-lib) ## What it measures -The driver times each call across four phases and prints a table with real +The driver times each call across five phases and prints a table with real numbers (mean, p50, p95, p99, min, max): 1. **logjet file (`LogjetWriter::push`)** — appending one record straight to a @@ -19,10 +19,29 @@ numbers (mean, p50, p95, p99, min, max): persistent gRPC channel (Ticket 1). 4. **backend OTLP/gRPC (batch=N)** — `lj_logger_log_batch()` sending N records in one request over the reused channel (Ticket 2). Reported per-record amortized. +5. **backend OTLP/gRPC (async enqueue)** — `lj_logger_log_async()` hands the send + to a background runtime and returns immediately (Ticket 3). The row is the + caller-thread enqueue cost; the demo then calls `lj_logger_flush()` and prints + the async error/dropped counters. This makes the finding explicit: the file write is cheap (µs); the per-connection backend send is the expensive part (~ms); connection reuse helps, -and batching brings the per-record cost back down toward the file-write cost. +batching brings the per-record cost down toward the file-write cost, and async +removes the network round-trip from the caller thread entirely. + +## Async backpressure + +`lj_logger_log_async` never blocks the caller. Outstanding sends are bounded by a +backpressure policy set via `lj_logger_set_backpressure(logger, model, capacity)`: + +- `LJ_BACKPRESSURE_UNBOUNDED` — spawn every send (risk: memory under load). +- `LJ_BACKPRESSURE_DROP` — bounded to `capacity` in-flight; drop + count when full. +- `LJ_BACKPRESSURE_BLOCK` — bounded; block the caller until a slot frees. + +Default is `DROP` with capacity `1024`. Observe behavior with +`lj_logger_async_errors`, `lj_logger_async_dropped`, and `lj_logger_async_inflight`, +and drain in-flight sends with `lj_logger_flush(logger, timeout_ms)` (also done +on `lj_logger_free`). The driver is Rust but calls the exported C ABI symbols of `liblogjet` — the same functions a C/C++ caller exercises through the shared library — while also @@ -48,6 +67,6 @@ on `127.0.0.1:4317`, runs the benchmark, prints the table, and stops `ljd`. ## Extending -Reuse (Ticket 1) and batching (Ticket 2) rows are in place. When further ABI -lands (e.g. async, Ticket 3), add a phase that calls the new symbol and a row to -the table; the harness is structured for it. +Reuse (Ticket 1), batching (Ticket 2), and async (Ticket 3) rows are in place. +When further ABI lands, add a phase that calls the new symbol and a row to the +table; the harness is structured for it. From f34aa2b85eb462e99e763269d596afb1efcd3119 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 14:52:40 +0200 Subject: [PATCH 09/21] Add index comparison column for the benchmark --- demo/benchmark-clib/README.md | 4 +++- demo/benchmark-clib/main.rs | 41 ++++++++++++++++++----------------- 2 files changed, 24 insertions(+), 21 deletions(-) diff --git a/demo/benchmark-clib/README.md b/demo/benchmark-clib/README.md index 72b110a..a302922 100644 --- a/demo/benchmark-clib/README.md +++ b/demo/benchmark-clib/README.md @@ -9,7 +9,9 @@ Reference: [`demo/cpp-shared-lib`](../cpp-shared-lib) ## What it measures The driver times each call across five phases and prints a table with real -numbers (mean, p50, p95, p99, min, max): +numbers (mean, p50, p95, p99, min, max) plus an `index` column — the improvement +factor `per-connection mean / row mean` (baseline = per-connection; the +`logjet file` row's index is a no-network reference floor): 1. **logjet file (`LogjetWriter::push`)** — appending one record straight to a `.logjet` file. No network. Isolates the storage/format layer. diff --git a/demo/benchmark-clib/main.rs b/demo/benchmark-clib/main.rs index 42c62ef..4d71343 100644 --- a/demo/benchmark-clib/main.rs +++ b/demo/benchmark-clib/main.rs @@ -131,15 +131,20 @@ fn main() { let batch_label = format!("backend OTLP/gRPC (batch={batch_size})"); let async_stats = summarize(async_phase.samples); - print_table(&[ - ("logjet file (LogjetWriter::push)", &file_stats), - ("backend OTLP/gRPC (per-connection)", &per_connection_stats), - ("backend OTLP/gRPC (reuse)", &reuse_stats), - (batch_label.as_str(), &batch_stats), - ("backend OTLP/gRPC (async enqueue)", &async_stats), - ]); + let baseline = per_connection_stats.mean; + print_table( + &[ + ("logjet file (LogjetWriter::push)", &file_stats), + ("backend OTLP/gRPC (per-connection)", &per_connection_stats), + ("backend OTLP/gRPC (reuse)", &reuse_stats), + (batch_label.as_str(), &batch_stats), + ("backend OTLP/gRPC (async enqueue)", &async_stats), + ], + baseline, + ); println!(); + println!("index = per-connection mean / row mean (baseline = per-connection; logjet file is a no-network reference)"); println!("note: batch row is per-record amortized; raw per-batch-call mean: {}", fmt_dur(raw_batch_mean)); println!( "note: async row is the caller-thread enqueue cost (fire-and-forget); flush: {}, errors: {}, dropped: {}", @@ -148,15 +153,6 @@ fn main() { async_phase.dropped, ); println!("reuse first/cold call (one-time connect): {}", fmt_dur(reuse_cold)); - if reuse_stats.mean > 0.0 { - println!("backend speedup (mean, per-connection -> reuse): {:.1}x", per_connection_stats.mean / reuse_stats.mean); - } - if batch_stats.mean > 0.0 { - println!("backend speedup (mean, per-connection -> batch): {:.1}x", per_connection_stats.mean / batch_stats.mean); - } - if async_stats.mean > 0.0 { - println!("backend speedup (mean, per-connection -> async enqueue): {:.1}x", per_connection_stats.mean / async_stats.mean); - } } fn run_file_phase(count: usize) -> std::io::Result> { @@ -370,12 +366,16 @@ fn fmt_dur(ns: f64) -> String { } } -fn print_table(rows: &[(&str, &Stats)]) { - println!("{:<36} {:>7} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11}", "path", "calls", "total", "mean", "p50", "p95", "p99", "min", "max"); - println!("{}", "-".repeat(36 + 7 + 11 * 7 + 8)); +fn print_table(rows: &[(&str, &Stats)], baseline: f64) { + println!( + "{:<36} {:>7} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>9}", + "path", "calls", "total", "mean", "p50", "p95", "p99", "min", "max", "index" + ); + println!("{}", "-".repeat(36 + 7 + 11 * 7 + 8 + 10)); for (name, stats) in rows { + let index = if stats.mean > 0.0 && baseline > 0.0 { format!("{:.1}x", baseline / stats.mean) } else { "-".to_string() }; println!( - "{:<36} {:>7} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11}", + "{:<36} {:>7} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>11} {:>9}", name, stats.count, fmt_dur(stats.total), @@ -385,6 +385,7 @@ fn print_table(rows: &[(&str, &Stats)]) { fmt_dur(stats.p99), fmt_dur(stats.min), fmt_dur(stats.max), + index, ); } let _ = std::io::stdout().flush(); From 3b20b37a510f8d977d88aad83b458ef64701f3a9 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 14:53:06 +0200 Subject: [PATCH 10/21] Cargo reformatting --- demo/benchmark-clib/main.rs | 4 +- demo/src/bin/metrics-emitter.rs | 7 +- demo/src/bin/metrics-grpc-emitter.rs | 4 +- demo/src/bin/multi-signal-emitter.rs | 21 ++-- demo/src/bin/traces-emitter.rs | 7 +- demo/src/bin/traces-grpc-emitter.rs | 4 +- demo/src/lib.rs | 27 ++--- liblogjet/src/lib.rs | 4 +- ljx/src/commands/export.rs | 3 +- ljx/src/commands/view/detail.rs | 45 ++++---- ljx/tests/unit/commands/export_ut.rs | 29 ++++- ljx/tests/unit/commands/view_ut.rs | 156 +++++++++++++++++++-------- logjetd/src/daemon.rs | 45 ++++---- logjetd/src/replay.rs | 19 +++- logjetd/tests/bridge_flows.rs | 4 +- logjetd/tests/unit/daemon_utst.rs | 24 +++-- plugins/parquet-exporter/src/lib.rs | 106 +++++++++++++----- tests/ljx_export.rs | 16 +-- 18 files changed, 319 insertions(+), 206 deletions(-) diff --git a/demo/benchmark-clib/main.rs b/demo/benchmark-clib/main.rs index 4d71343..39ac5c4 100644 --- a/demo/benchmark-clib/main.rs +++ b/demo/benchmark-clib/main.rs @@ -20,8 +20,8 @@ use std::ptr; use std::time::{Instant, SystemTime, UNIX_EPOCH}; use liblogjet::{ - LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, lj_logger_log, lj_logger_log_async, - lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, + LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, + lj_logger_log, lj_logger_log_async, lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, }; use logjet::{LogjetWriter, RecordType}; diff --git a/demo/src/bin/metrics-emitter.rs b/demo/src/bin/metrics-emitter.rs index 493dc6e..351fba4 100644 --- a/demo/src/bin/metrics-emitter.rs +++ b/demo/src/bin/metrics-emitter.rs @@ -15,11 +15,8 @@ fn main() { let addr = &args[1]; let count: u64 = args.get(2).and_then(|s| s.parse().ok()).unwrap_or(20); - let endpoint = if addr.starts_with("http://") || addr.starts_with("https://") { - format!("{addr}/v1/metrics") - } else { - format!("http://{addr}/v1/metrics") - }; + let endpoint = + if addr.starts_with("http://") || addr.starts_with("https://") { format!("{addr}/v1/metrics") } else { format!("http://{addr}/v1/metrics") }; println!("metrics-emitter sending {count} batches to {endpoint}"); diff --git a/demo/src/bin/metrics-grpc-emitter.rs b/demo/src/bin/metrics-grpc-emitter.rs index abfbeda..527d62d 100644 --- a/demo/src/bin/metrics-grpc-emitter.rs +++ b/demo/src/bin/metrics-grpc-emitter.rs @@ -31,7 +31,9 @@ async fn main() -> Result<(), Box> { Ok(()) } -async fn send_batch(client: &mut MetricsServiceClient, request: ExportMetricsServiceRequest) -> Result<(), Box> { +async fn send_batch( + client: &mut MetricsServiceClient, request: ExportMetricsServiceRequest, +) -> Result<(), Box> { client.export(Request::new(request)).await?; Ok(()) } diff --git a/demo/src/bin/multi-signal-emitter.rs b/demo/src/bin/multi-signal-emitter.rs index f5fa313..c843495 100644 --- a/demo/src/bin/multi-signal-emitter.rs +++ b/demo/src/bin/multi-signal-emitter.rs @@ -15,21 +15,12 @@ fn main() { let addr = &args[1]; let count: u64 = args.get(2).and_then(|s| s.parse().ok()).unwrap_or(8); - let logs_endpoint = if addr.starts_with("http://") || addr.starts_with("https://") { - format!("{addr}/v1/logs") - } else { - format!("http://{addr}/v1/logs") - }; - let metrics_endpoint = if addr.starts_with("http://") || addr.starts_with("https://") { - format!("{addr}/v1/metrics") - } else { - format!("http://{addr}/v1/metrics") - }; - let traces_endpoint = if addr.starts_with("http://") || addr.starts_with("https://") { - format!("{addr}/v1/traces") - } else { - format!("http://{addr}/v1/traces") - }; + let logs_endpoint = + if addr.starts_with("http://") || addr.starts_with("https://") { format!("{addr}/v1/logs") } else { format!("http://{addr}/v1/logs") }; + let metrics_endpoint = + if addr.starts_with("http://") || addr.starts_with("https://") { format!("{addr}/v1/metrics") } else { format!("http://{addr}/v1/metrics") }; + let traces_endpoint = + if addr.starts_with("http://") || addr.starts_with("https://") { format!("{addr}/v1/traces") } else { format!("http://{addr}/v1/traces") }; println!("multi-signal-emitter sending {count} batches per signal (logs, metrics, traces) to {addr}"); diff --git a/demo/src/bin/traces-emitter.rs b/demo/src/bin/traces-emitter.rs index dadc277..f329e4c 100644 --- a/demo/src/bin/traces-emitter.rs +++ b/demo/src/bin/traces-emitter.rs @@ -15,11 +15,8 @@ fn main() { let addr = &args[1]; let count: u64 = args.get(2).and_then(|s| s.parse().ok()).unwrap_or(15); - let endpoint = if addr.starts_with("http://") || addr.starts_with("https://") { - format!("{addr}/v1/traces") - } else { - format!("http://{addr}/v1/traces") - }; + let endpoint = + if addr.starts_with("http://") || addr.starts_with("https://") { format!("{addr}/v1/traces") } else { format!("http://{addr}/v1/traces") }; println!("traces-emitter sending {count} batches to {endpoint}"); diff --git a/demo/src/bin/traces-grpc-emitter.rs b/demo/src/bin/traces-grpc-emitter.rs index 6a73a31..71200b2 100644 --- a/demo/src/bin/traces-grpc-emitter.rs +++ b/demo/src/bin/traces-grpc-emitter.rs @@ -31,7 +31,9 @@ async fn main() -> Result<(), Box> { Ok(()) } -async fn send_batch(client: &mut TraceServiceClient, request: ExportTraceServiceRequest) -> Result<(), Box> { +async fn send_batch( + client: &mut TraceServiceClient, request: ExportTraceServiceRequest, +) -> Result<(), Box> { client.export(Request::new(request)).await?; Ok(()) } diff --git a/demo/src/lib.rs b/demo/src/lib.rs index 0805dc4..01149da 100644 --- a/demo/src/lib.rs +++ b/demo/src/lib.rs @@ -9,14 +9,12 @@ use std::time::{Duration, SystemTime, UNIX_EPOCH}; use colored::Colorize; use opentelemetry_proto::tonic::collector::logs::v1::ExportLogsServiceRequest; use opentelemetry_proto::tonic::collector::metrics::v1::ExportMetricsServiceRequest; +use opentelemetry_proto::tonic::collector::trace::v1::ExportTraceServiceRequest; use opentelemetry_proto::tonic::common::v1::{AnyValue, InstrumentationScope, KeyValue}; use opentelemetry_proto::tonic::logs::v1::{LogRecord, ResourceLogs, ScopeLogs, SeverityNumber}; use opentelemetry_proto::tonic::metrics::v1::number_data_point::Value as DataPointValue; -use opentelemetry_proto::tonic::metrics::v1::{ - AggregationTemporality, Gauge, Metric, NumberDataPoint, ResourceMetrics, ScopeMetrics, Sum, -}; +use opentelemetry_proto::tonic::metrics::v1::{AggregationTemporality, Gauge, Metric, NumberDataPoint, ResourceMetrics, ScopeMetrics, Sum}; use opentelemetry_proto::tonic::resource::v1::Resource; -use opentelemetry_proto::tonic::collector::trace::v1::ExportTraceServiceRequest; use opentelemetry_proto::tonic::trace::v1::{ResourceSpans, ScopeSpans, Span}; use prost::Message; use rustls::pki_types::{CertificateDer, PrivateKeyDer, ServerName}; @@ -131,10 +129,7 @@ pub fn build_metrics_request(sequence: u64) -> ExportMetricsServiceRequest { let request_count = sequence * 100 + 42; let resource = Resource { - attributes: vec![ - string_attr("service.name", "metrics-demo"), - string_attr("host.name", "garage-rig"), - ], + attributes: vec![string_attr("service.name", "metrics-demo"), string_attr("host.name", "garage-rig")], dropped_attributes_count: 0, entity_refs: Vec::new(), }; @@ -185,11 +180,7 @@ pub fn build_metrics_request(sequence: u64) -> ExportMetricsServiceRequest { ExportMetricsServiceRequest { resource_metrics: vec![ResourceMetrics { resource: Some(resource), - scope_metrics: vec![ScopeMetrics { - scope: Some(scope), - metrics: vec![cpu_metric, requests_metric], - schema_url: String::new(), - }], + scope_metrics: vec![ScopeMetrics { scope: Some(scope), metrics: vec![cpu_metric, requests_metric], schema_url: String::new() }], schema_url: String::new(), }], } @@ -537,10 +528,7 @@ pub fn build_trace_request(sequence: u64) -> ExportTraceServiceRequest { ExportTraceServiceRequest { resource_spans: vec![ResourceSpans { resource: Some(Resource { - attributes: vec![ - string_attr("service.name", "traces-demo"), - string_attr("host.name", "garage-rig"), - ], + attributes: vec![string_attr("service.name", "traces-demo"), string_attr("host.name", "garage-rig")], dropped_attributes_count: 0, entity_refs: Vec::new(), }), @@ -582,10 +570,7 @@ pub fn build_trace_request(sequence: u64) -> ExportTraceServiceRequest { kind: 3, start_time_unix_nano: base_nanos + sequence * 1_000_000 + 2_000_000, end_time_unix_nano: base_nanos + sequence * 1_000_000 + ((sequence % 50 + 1) * 1_000_000) - 1_000_000, - attributes: vec![ - string_attr("db.system", "postgres"), - string_attr("db.statement", "SELECT * FROM items WHERE id = $1"), - ], + attributes: vec![string_attr("db.system", "postgres"), string_attr("db.statement", "SELECT * FROM items WHERE id = $1")], dropped_attributes_count: 0, events: vec![], dropped_events_count: 0, diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index 3e64024..a8e2ed9 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -693,7 +693,9 @@ fn key_value(key: impl Into, value: AnyValue) -> KeyValue { fn send_request(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { match &logger.backend { Backend::Http(endpoint) => post_otlp_http(endpoint, logger.timeout, &request).map_err(|err| err.to_string()), - Backend::Grpc(client) => client.runtime.block_on(send_otlp_grpc(client.shared.endpoint.clone(), logger.timeout, request)).map_err(|err| err.to_string()), + Backend::Grpc(client) => { + client.runtime.block_on(send_otlp_grpc(client.shared.endpoint.clone(), logger.timeout, request)).map_err(|err| err.to_string()) + } } } diff --git a/ljx/src/commands/export.rs b/ljx/src/commands/export.rs index de61bdb..2abb243 100644 --- a/ljx/src/commands/export.rs +++ b/ljx/src/commands/export.rs @@ -473,7 +473,8 @@ fn data_point_value_to_json(value: &opentelemetry_proto::tonic::metrics::v1::num } } -fn flatten_otlp_attrs_into_json( target: &mut JsonMap, attrs: &[opentelemetry_proto::tonic::common::v1::KeyValue], preview_bytes: Option, +fn flatten_otlp_attrs_into_json( + target: &mut JsonMap, attrs: &[opentelemetry_proto::tonic::common::v1::KeyValue], preview_bytes: Option, ) { for attr in attrs { let key = attr.key.replace('.', "_"); diff --git a/ljx/src/commands/view/detail.rs b/ljx/src/commands/view/detail.rs index 588628a..74e3566 100644 --- a/ljx/src/commands/view/detail.rs +++ b/ljx/src/commands/view/detail.rs @@ -1,9 +1,9 @@ use chrono::{TimeZone, Utc}; use opentelemetry_proto::tonic::collector::logs::v1::ExportLogsServiceRequest; use opentelemetry_proto::tonic::collector::metrics::v1::ExportMetricsServiceRequest; +use opentelemetry_proto::tonic::collector::trace::v1::ExportTraceServiceRequest; use opentelemetry_proto::tonic::common::v1::any_value::Value; use opentelemetry_proto::tonic::common::v1::{AnyValue, KeyValue}; -use opentelemetry_proto::tonic::collector::trace::v1::ExportTraceServiceRequest; use opentelemetry_proto::tonic::metrics::v1::metric::Data as MetricData; use prost::Message; use ratatui::style::{Color, Modifier, Style}; @@ -289,11 +289,7 @@ pub(crate) fn extract_otlp_metrics_summary(payload: &[u8]) -> Option { } } - if parts.is_empty() { - None - } else { - Some(parts.join(", ")) - } + if parts.is_empty() { None } else { Some(parts.join(", ")) } } pub(crate) fn extract_otlp_traces_summary(payload: &[u8]) -> Option { @@ -315,11 +311,7 @@ pub(crate) fn extract_otlp_traces_summary(payload: &[u8]) -> Option { } } - if parts.is_empty() { - None - } else { - Some(parts.join(", ")) - } + if parts.is_empty() { None } else { Some(parts.join(", ")) } } pub(crate) fn extract_otlp_traces_message(payload: &[u8]) -> Option { @@ -353,11 +345,7 @@ pub(crate) fn extract_otlp_traces_message(payload: &[u8]) -> Option { } } - if lines.is_empty() { - None - } else { - Some(lines.join("\n")) - } + if lines.is_empty() { None } else { Some(lines.join("\n")) } } fn format_span_kind(kind: i32) -> String { @@ -393,13 +381,22 @@ pub(crate) fn extract_otlp_metrics_message(payload: &[u8]) -> Option { Some(Data::Gauge(g)) => { lines.push(" Type: Gauge".to_string()); for dp in &g.data_points { - lines.push(format!(" - time={}, value={}", format_timestamp(dp.time_unix_nano), dp.value.as_ref().map(format_data_point_value).unwrap_or_default())); + lines.push(format!( + " - time={}, value={}", + format_timestamp(dp.time_unix_nano), + dp.value.as_ref().map(format_data_point_value).unwrap_or_default() + )); } } Some(Data::Sum(s)) => { lines.push(format!(" Type: Sum (monotonic={}, temporality={})", s.is_monotonic, s.aggregation_temporality)); for dp in &s.data_points { - lines.push(format!(" - time={}, start_time={}, value={}", format_timestamp(dp.time_unix_nano), format_timestamp(dp.start_time_unix_nano), dp.value.as_ref().map(format_data_point_value).unwrap_or_default())); + lines.push(format!( + " - time={}, start_time={}, value={}", + format_timestamp(dp.time_unix_nano), + format_timestamp(dp.start_time_unix_nano), + dp.value.as_ref().map(format_data_point_value).unwrap_or_default() + )); } } Some(Data::Histogram(h)) => { @@ -427,11 +424,7 @@ pub(crate) fn extract_otlp_metrics_message(payload: &[u8]) -> Option { } } - if lines.is_empty() { - None - } else { - Some(lines.join("\n")) - } + if lines.is_empty() { None } else { Some(lines.join("\n")) } } fn format_data_point_value(value: &opentelemetry_proto::tonic::metrics::v1::number_data_point::Value) -> String { @@ -624,7 +617,7 @@ fn render_modal_metrics_info_entries(detail: &DetailRecord) -> Vec<(String, Stri for resource_metrics in &batch.resource_metrics { for scope_metrics in &resource_metrics.scope_metrics { for metric in &scope_metrics.metrics { - let prefix = format!("metric.{}" , metric.name); + let prefix = format!("metric.{}", metric.name); entries.push((format!("{prefix}.unit"), metric.unit.clone())); if !metric.description.is_empty() { entries.push((format!("{prefix}.description"), metric.description.clone())); @@ -1018,7 +1011,9 @@ fn export_metrics_ndjson(detail: &DetailRecord) -> Vec { fn data_point_value_to_json(value: &opentelemetry_proto::tonic::metrics::v1::number_data_point::Value) -> JsonValue { match value { - opentelemetry_proto::tonic::metrics::v1::number_data_point::Value::AsDouble(v) => serde_json::Number::from_f64(*v).map(JsonValue::Number).unwrap_or(JsonValue::Null), + opentelemetry_proto::tonic::metrics::v1::number_data_point::Value::AsDouble(v) => { + serde_json::Number::from_f64(*v).map(JsonValue::Number).unwrap_or(JsonValue::Null) + } opentelemetry_proto::tonic::metrics::v1::number_data_point::Value::AsInt(v) => JsonValue::Number((*v).into()), } } diff --git a/ljx/tests/unit/commands/export_ut.rs b/ljx/tests/unit/commands/export_ut.rs index 0694de1..7fcf394 100644 --- a/ljx/tests/unit/commands/export_ut.rs +++ b/ljx/tests/unit/commands/export_ut.rs @@ -162,12 +162,20 @@ fn export_ndjson_objects_includes_otlp_metrics_fields() { let batch = ExportMetricsServiceRequest { resource_metrics: vec![ResourceMetrics { resource: Some(Resource { - attributes: vec![KeyValue { key: "service.name".to_string(), value: Some(AnyValue { value: Some(Value::StringValue("metrics-svc".to_string())) }) }], + attributes: vec![KeyValue { + key: "service.name".to_string(), + value: Some(AnyValue { value: Some(Value::StringValue("metrics-svc".to_string())) }), + }], dropped_attributes_count: 0, entity_refs: vec![], }), scope_metrics: vec![ScopeMetrics { - scope: Some(InstrumentationScope { name: "demo.metrics.scope".to_string(), version: "1.0.0".to_string(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "demo.metrics.scope".to_string(), + version: "1.0.0".to_string(), + attributes: vec![], + dropped_attributes_count: 0, + }), metrics: vec![metric], schema_url: String::new(), }], @@ -194,12 +202,20 @@ fn export_ndjson_objects_includes_otlp_traces_fields() { let batch = ExportTraceServiceRequest { resource_spans: vec![ResourceSpans { resource: Some(Resource { - attributes: vec![KeyValue { key: "service.name".to_string(), value: Some(AnyValue { value: Some(Value::StringValue("traces-svc".to_string())) }) }], + attributes: vec![KeyValue { + key: "service.name".to_string(), + value: Some(AnyValue { value: Some(Value::StringValue("traces-svc".to_string())) }), + }], dropped_attributes_count: 0, entity_refs: vec![], }), scope_spans: vec![ScopeSpans { - scope: Some(InstrumentationScope { name: "demo.traces.scope".to_string(), version: "2.0.0".to_string(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "demo.traces.scope".to_string(), + version: "2.0.0".to_string(), + attributes: vec![], + dropped_attributes_count: 0, + }), spans: vec![Span { trace_id: vec![1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16], span_id: vec![16, 17, 18, 19, 20, 21, 22, 23], @@ -208,7 +224,10 @@ fn export_ndjson_objects_includes_otlp_traces_fields() { kind: 2, start_time_unix_nano: 1_700_000_000_000_000_000, end_time_unix_nano: 1_700_000_000_000_000_100, - attributes: vec![KeyValue { key: "http.method".to_string(), value: Some(AnyValue { value: Some(Value::StringValue("GET".to_string())) }) }], + attributes: vec![KeyValue { + key: "http.method".to_string(), + value: Some(AnyValue { value: Some(Value::StringValue("GET".to_string())) }), + }], dropped_attributes_count: 0, events: vec![], dropped_events_count: 0, diff --git a/ljx/tests/unit/commands/view_ut.rs b/ljx/tests/unit/commands/view_ut.rs index 5331c25..62be42a 100644 --- a/ljx/tests/unit/commands/view_ut.rs +++ b/ljx/tests/unit/commands/view_ut.rs @@ -891,7 +891,12 @@ fn summary_decodes_otlp_metrics_payload() { resource_metrics: vec![ResourceMetrics { resource: Some(Resource { attributes: vec![], dropped_attributes_count: 0, entity_refs: vec![] }), scope_metrics: vec![ScopeMetrics { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), metrics: vec![metric], schema_url: String::new(), }], @@ -900,7 +905,14 @@ fn summary_decodes_otlp_metrics_payload() { }; let payload = batch.encode_to_vec(); let detail = DetailRecord { - meta: EntryMeta { offset: 0, record_type: RecordType::Metrics, seq: 1, ts_unix_ns: 2, payload_len: payload.len() as u64, source_path: "a.logjet".into() }, + meta: EntryMeta { + offset: 0, + record_type: RecordType::Metrics, + seq: 1, + ts_unix_ns: 2, + payload_len: payload.len() as u64, + source_path: "a.logjet".into(), + }, payload, }; assert_eq!(format_summary(&detail, false), "cpu.usage=45.5%"); @@ -932,7 +944,12 @@ fn modal_message_decodes_otlp_metrics_payload() { resource_metrics: vec![ResourceMetrics { resource: Some(Resource { attributes: vec![], dropped_attributes_count: 0, entity_refs: vec![] }), scope_metrics: vec![ScopeMetrics { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), metrics: vec![metric], schema_url: String::new(), }], @@ -941,7 +958,14 @@ fn modal_message_decodes_otlp_metrics_payload() { }; let payload = batch.encode_to_vec(); let detail = DetailRecord { - meta: EntryMeta { offset: 0, record_type: RecordType::Metrics, seq: 1, ts_unix_ns: 2, payload_len: payload.len() as u64, source_path: "a.logjet".into() }, + meta: EntryMeta { + offset: 0, + record_type: RecordType::Metrics, + seq: 1, + ts_unix_ns: 2, + payload_len: payload.len() as u64, + source_path: "a.logjet".into(), + }, payload, }; let message = render_modal_message(&detail, false); @@ -975,7 +999,12 @@ fn modal_info_entries_decodes_otlp_metrics_payload() { resource_metrics: vec![ResourceMetrics { resource: Some(Resource { attributes: vec![], dropped_attributes_count: 0, entity_refs: vec![] }), scope_metrics: vec![ScopeMetrics { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), metrics: vec![metric], schema_url: String::new(), }], @@ -984,7 +1013,14 @@ fn modal_info_entries_decodes_otlp_metrics_payload() { }; let payload = batch.encode_to_vec(); let detail = DetailRecord { - meta: EntryMeta { offset: 0, record_type: RecordType::Metrics, seq: 1, ts_unix_ns: 2, payload_len: payload.len() as u64, source_path: "a.logjet".into() }, + meta: EntryMeta { + offset: 0, + record_type: RecordType::Metrics, + seq: 1, + ts_unix_ns: 2, + payload_len: payload.len() as u64, + source_path: "a.logjet".into(), + }, payload, }; let entries = render_modal_info_entries(&detail); @@ -1006,43 +1042,48 @@ fn summary_decodes_otlp_traces_payload() { entity_refs: vec![], }), scope_spans: vec![ScopeSpans { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), spans: vec![ Span { trace_id: vec![1, 2, 3, 4], span_id: vec![5, 6, 7, 8], parent_span_id: vec![], name: "GET /api".to_string(), - kind: 2, - start_time_unix_nano: 1_700_000_000_000_000_000, - end_time_unix_nano: 1_700_000_000_000_000_100, - attributes: vec![], - dropped_attributes_count: 0, - events: vec![], - dropped_events_count: 0, - links: vec![], - dropped_links_count: 0, - status: None, - flags: 0, - trace_state: String::new(), - }, - Span { - trace_id: vec![1, 2, 3, 4], - span_id: vec![9, 10, 11, 12], - parent_span_id: vec![5, 6, 7, 8], - name: "SELECT".to_string(), - kind: 3, - start_time_unix_nano: 1_700_000_000_000_000_050, - end_time_unix_nano: 1_700_000_000_000_000_080, - attributes: vec![], - dropped_attributes_count: 0, - events: vec![], - dropped_events_count: 0, - links: vec![], - dropped_links_count: 0, - status: None, - flags: 0, - trace_state: String::new(), + kind: 2, + start_time_unix_nano: 1_700_000_000_000_000_000, + end_time_unix_nano: 1_700_000_000_000_000_100, + attributes: vec![], + dropped_attributes_count: 0, + events: vec![], + dropped_events_count: 0, + links: vec![], + dropped_links_count: 0, + status: None, + flags: 0, + trace_state: String::new(), + }, + Span { + trace_id: vec![1, 2, 3, 4], + span_id: vec![9, 10, 11, 12], + parent_span_id: vec![5, 6, 7, 8], + name: "SELECT".to_string(), + kind: 3, + start_time_unix_nano: 1_700_000_000_000_000_050, + end_time_unix_nano: 1_700_000_000_000_000_080, + attributes: vec![], + dropped_attributes_count: 0, + events: vec![], + dropped_events_count: 0, + links: vec![], + dropped_links_count: 0, + status: None, + flags: 0, + trace_state: String::new(), }, ], schema_url: String::new(), @@ -1052,7 +1093,14 @@ fn summary_decodes_otlp_traces_payload() { }; let payload = batch.encode_to_vec(); let detail = DetailRecord { - meta: EntryMeta { offset: 0, record_type: RecordType::Traces, seq: 1, ts_unix_ns: 2, payload_len: payload.len() as u64, source_path: "a.logjet".into() }, + meta: EntryMeta { + offset: 0, + record_type: RecordType::Traces, + seq: 1, + ts_unix_ns: 2, + payload_len: payload.len() as u64, + source_path: "a.logjet".into(), + }, payload, }; let summary = format_summary(&detail, false); @@ -1066,7 +1114,12 @@ fn modal_message_decodes_otlp_traces_payload() { resource_spans: vec![ResourceSpans { resource: Some(Resource { attributes: vec![], dropped_attributes_count: 0, entity_refs: vec![] }), scope_spans: vec![ScopeSpans { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), spans: vec![Span { trace_id: vec![1, 2, 3, 4], span_id: vec![5, 6, 7, 8], @@ -1092,7 +1145,14 @@ fn modal_message_decodes_otlp_traces_payload() { }; let payload = batch.encode_to_vec(); let detail = DetailRecord { - meta: EntryMeta { offset: 0, record_type: RecordType::Traces, seq: 1, ts_unix_ns: 2, payload_len: payload.len() as u64, source_path: "a.logjet".into() }, + meta: EntryMeta { + offset: 0, + record_type: RecordType::Traces, + seq: 1, + ts_unix_ns: 2, + payload_len: payload.len() as u64, + source_path: "a.logjet".into(), + }, payload, }; let message = render_modal_message(&detail, false); @@ -1114,7 +1174,12 @@ fn modal_info_entries_decodes_otlp_traces_payload() { entity_refs: vec![], }), scope_spans: vec![ScopeSpans { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), spans: vec![ Span { trace_id: vec![1, 2, 3, 4], @@ -1160,7 +1225,14 @@ fn modal_info_entries_decodes_otlp_traces_payload() { }; let payload = batch.encode_to_vec(); let detail = DetailRecord { - meta: EntryMeta { offset: 0, record_type: RecordType::Traces, seq: 1, ts_unix_ns: 2, payload_len: payload.len() as u64, source_path: "a.logjet".into() }, + meta: EntryMeta { + offset: 0, + record_type: RecordType::Traces, + seq: 1, + ts_unix_ns: 2, + payload_len: payload.len() as u64, + source_path: "a.logjet".into(), + }, payload, }; let entries = render_modal_info_entries(&detail); diff --git a/logjetd/src/daemon.rs b/logjetd/src/daemon.rs index 9275cca..6a30cf6 100644 --- a/logjetd/src/daemon.rs +++ b/logjetd/src/daemon.rs @@ -284,8 +284,10 @@ fn ingest_loop( ); let runtime = tokio::runtime::Builder::new_multi_thread().enable_all().build().map_err(|err| io::Error::other(err.to_string()))?; - let logs_service = OtlpGrpcLogsService { spool: Arc::clone(&spool), next_seq: Arc::clone(&next_seq), ingest_policy: Arc::clone(&ingest_policy) }; - let metrics_service = OtlpGrpcMetricsService { spool: Arc::clone(&spool), next_seq: Arc::clone(&next_seq), ingest_policy: Arc::clone(&ingest_policy) }; + let logs_service = + OtlpGrpcLogsService { spool: Arc::clone(&spool), next_seq: Arc::clone(&next_seq), ingest_policy: Arc::clone(&ingest_policy) }; + let metrics_service = + OtlpGrpcMetricsService { spool: Arc::clone(&spool), next_seq: Arc::clone(&next_seq), ingest_policy: Arc::clone(&ingest_policy) }; let traces_service = OtlpGrpcTracesService { spool, next_seq, ingest_policy }; let grpc_tls = if ingest_tls.enable { Some(build_grpc_server_tls_config(&ingest_tls)?) } else { None }; @@ -365,15 +367,8 @@ async fn serve_otlp_http_connection( return Ok(()); }; - let svc = service_fn(move |req| { - handle_otlp_http_request( - req, - Arc::clone(&spool), - Arc::clone(&ingest_policy), - Arc::clone(&next_seq), - max_batch_bytes, - ) - }); + let svc = + service_fn(move |req| handle_otlp_http_request(req, Arc::clone(&spool), Arc::clone(&ingest_policy), Arc::clone(&next_seq), max_batch_bytes)); if let Some(acceptor) = tls_acceptor { let tls_stream = acceptor.accept(stream).await.map_err(|err| io::Error::other(err.to_string()))?; @@ -398,8 +393,7 @@ where let is_metrics = req.uri().path() == "/v1/metrics"; let is_traces = req.uri().path() == "/v1/traces"; - let content_encoding = - req.headers().get("content-encoding").and_then(|v| v.to_str().ok()).map(|s| s.to_string()); + let content_encoding = req.headers().get("content-encoding").and_then(|v| v.to_str().ok()).map(|s| s.to_string()); let (parts, body) = req.into_parts(); @@ -407,8 +401,8 @@ where if let Some(len) = parts.headers.get("content-length").and_then(|v| v.to_str().ok()).and_then(|v| v.parse::().ok()) && len > max_batch_bytes { - ingest_policy.note_oversize()?; - return Ok(HyperResponse::builder().status(StatusCode::PAYLOAD_TOO_LARGE).body(Full::new(Bytes::from("payload too large"))).unwrap()); + ingest_policy.note_oversize()?; + return Ok(HyperResponse::builder().status(StatusCode::PAYLOAD_TOO_LARGE).body(Full::new(Bytes::from("payload too large"))).unwrap()); } let collected = body.collect().await.map_err(|err| io::Error::other(format!("failed to read request body: {err}")))?; @@ -448,10 +442,9 @@ where append_batch_record(&spool, record)?; Ok(HyperResponse::builder().status(StatusCode::OK).body(Full::new(Bytes::new())).unwrap()) } - Err(err) => Ok(HyperResponse::builder() - .status(StatusCode::BAD_REQUEST) - .body(Full::new(Bytes::from(format!("decode error: {err}")))) - .unwrap()), + Err(err) => { + Ok(HyperResponse::builder().status(StatusCode::BAD_REQUEST).body(Full::new(Bytes::from(format!("decode error: {err}")))).unwrap()) + } } } else if is_traces { match ExportTraceServiceRequest::decode(body_vec.as_slice()) { @@ -472,10 +465,9 @@ where append_batch_record(&spool, record)?; Ok(HyperResponse::builder().status(StatusCode::OK).body(Full::new(Bytes::new())).unwrap()) } - Err(err) => Ok(HyperResponse::builder() - .status(StatusCode::BAD_REQUEST) - .body(Full::new(Bytes::from(format!("decode error: {err}")))) - .unwrap()), + Err(err) => { + Ok(HyperResponse::builder().status(StatusCode::BAD_REQUEST).body(Full::new(Bytes::from(format!("decode error: {err}")))).unwrap()) + } } } else { match ExportLogsServiceRequest::decode(body_vec.as_slice()) { @@ -496,10 +488,9 @@ where append_batch_record(&spool, record)?; Ok(HyperResponse::builder().status(StatusCode::OK).body(Full::new(Bytes::new())).unwrap()) } - Err(err) => Ok(HyperResponse::builder() - .status(StatusCode::BAD_REQUEST) - .body(Full::new(Bytes::from(format!("decode error: {err}")))) - .unwrap()), + Err(err) => { + Ok(HyperResponse::builder().status(StatusCode::BAD_REQUEST).body(Full::new(Bytes::from(format!("decode error: {err}")))).unwrap()) + } } } } diff --git a/logjetd/src/replay.rs b/logjetd/src/replay.rs index 5b6d6c1..2015455 100644 --- a/logjetd/src/replay.rs +++ b/logjetd/src/replay.rs @@ -345,10 +345,18 @@ impl BridgeStats { fn drop_summary(&self) -> String { let mut parts = Vec::new(); - if self.drops_logs > 0 { parts.push(format!("logs_drops={}", self.drops_logs)); } - if self.drops_metrics > 0 { parts.push(format!("metrics_drops={}", self.drops_metrics)); } - if self.drops_traces > 0 { parts.push(format!("traces_drops={}", self.drops_traces)); } - if self.drops_events > 0 { parts.push(format!("events_drops={}", self.drops_events)); } + if self.drops_logs > 0 { + parts.push(format!("logs_drops={}", self.drops_logs)); + } + if self.drops_metrics > 0 { + parts.push(format!("metrics_drops={}", self.drops_metrics)); + } + if self.drops_traces > 0 { + parts.push(format!("traces_drops={}", self.drops_traces)); + } + if self.drops_events > 0 { + parts.push(format!("events_drops={}", self.drops_events)); + } if parts.is_empty() { "drops=0".to_string() } else { parts.join(" ") } } @@ -551,7 +559,8 @@ impl GrpcCollectorConnection { } fn reconnect(&mut self) -> io::Result<()> { - let (client, metrics_client, traces_client) = self.runtime.block_on(connect_grpc_with_collector(&self.endpoint, self.timeout, Some(&self.collector)))?; + let (client, metrics_client, traces_client) = + self.runtime.block_on(connect_grpc_with_collector(&self.endpoint, self.timeout, Some(&self.collector)))?; self.client = client; self.metrics_client = metrics_client; self.traces_client = traces_client; diff --git a/logjetd/tests/bridge_flows.rs b/logjetd/tests/bridge_flows.rs index e8fca39..2e632be 100644 --- a/logjetd/tests/bridge_flows.rs +++ b/logjetd/tests/bridge_flows.rs @@ -7,8 +7,8 @@ use std::thread; use std::time::Duration; use common::{ - ChildGuard, MockCollector, MockGrpcCollector, ReservedPort, TestDir, connect_replay_client, ensure_rustls_provider, free_port, ljd_command, post_otlp_http, - read_replay_message, replay_messages, reserve_port, wait_for_tcp, wait_until, write_fake_grpc_tls_files, + ChildGuard, MockCollector, MockGrpcCollector, ReservedPort, TestDir, connect_replay_client, ensure_rustls_provider, free_port, ljd_command, + post_otlp_http, read_replay_message, replay_messages, reserve_port, wait_for_tcp, wait_until, write_fake_grpc_tls_files, }; fn http_collector(port: ReservedPort) -> io::Result { diff --git a/logjetd/tests/unit/daemon_utst.rs b/logjetd/tests/unit/daemon_utst.rs index dabcd46..40bc565 100644 --- a/logjetd/tests/unit/daemon_utst.rs +++ b/logjetd/tests/unit/daemon_utst.rs @@ -48,9 +48,7 @@ async fn handle_otlp_http_request_logs_accepts_valid_batch() { log_records: vec![LogRecord { severity_number: 13, severity_text: "WARN".to_string(), - body: Some(AnyValue { - value: Some(opentelemetry_proto::tonic::common::v1::any_value::Value::StringValue("warn".to_string())), - }), + body: Some(AnyValue { value: Some(opentelemetry_proto::tonic::common::v1::any_value::Value::StringValue("warn".to_string())) }), ..Default::default() }], schema_url: String::new(), @@ -223,11 +221,7 @@ async fn handle_otlp_http_request_unknown_path_returns_404() { })); let next_seq = Arc::new(AtomicU64::new(1)); - let req = Request::builder() - .method(Method::POST) - .uri("/v1/unknown") - .body(Full::new(Bytes::new())) - .unwrap(); + let req = Request::builder().method(Method::POST).uri("/v1/unknown").body(Full::new(Bytes::new())).unwrap(); let response = handle_otlp_http_request(req, shared_spool, policy, next_seq, 1024).await.unwrap(); assert_eq!(response.status(), StatusCode::NOT_FOUND); } @@ -475,7 +469,12 @@ fn extract_batch_timestamp_metrics_finds_first_datapoint_time() { resource_metrics: vec![ResourceMetrics { resource: Some(Resource { attributes: vec![], dropped_attributes_count: 0, entity_refs: vec![] }), scope_metrics: vec![ScopeMetrics { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), metrics: vec![metric], schema_url: String::new(), }], @@ -497,7 +496,12 @@ fn extract_batch_timestamp_traces_finds_first_span_start_time() { resource_spans: vec![ResourceSpans { resource: Some(Resource { attributes: vec![], dropped_attributes_count: 0, entity_refs: vec![] }), scope_spans: vec![ScopeSpans { - scope: Some(InstrumentationScope { name: "test".to_string(), version: String::new(), attributes: vec![], dropped_attributes_count: 0 }), + scope: Some(InstrumentationScope { + name: "test".to_string(), + version: String::new(), + attributes: vec![], + dropped_attributes_count: 0, + }), spans: vec![Span { trace_id: vec![1, 2, 3, 4], span_id: vec![5, 6, 7, 8], diff --git a/plugins/parquet-exporter/src/lib.rs b/plugins/parquet-exporter/src/lib.rs index 123d710..55e69bd 100644 --- a/plugins/parquet-exporter/src/lib.rs +++ b/plugins/parquet-exporter/src/lib.rs @@ -135,11 +135,7 @@ impl ParquetExporter { if record.struct_size < std::mem::size_of::() as u32 { return self.fail_status( LJX_EXPORT_STATUS_BAD_ARG, - format!( - "record struct_size {} is smaller than host ABI expects {}", - record.struct_size, - std::mem::size_of::() - ), + format!("record struct_size {} is smaller than host ABI expects {}", record.struct_size, std::mem::size_of::()), ); } if record.payload.ptr.is_null() && record.payload.len != 0 { @@ -246,7 +242,7 @@ impl ParquetExporter { let request = match ExportMetricsServiceRequest::decode(payload) { Ok(request) => request, Err(err) => { - return self.fail_status(LJX_EXPORT_STATUS_ERROR, format!("failed to decode OTLP metrics payload at seq {}: {err}", record.seq)) + return self.fail_status(LJX_EXPORT_STATUS_ERROR, format!("failed to decode OTLP metrics payload at seq {}: {err}", record.seq)); } }; @@ -269,7 +265,18 @@ impl ParquetExporter { match data { MetricData::Gauge(gauge) => { for dp in &gauge.data_points { - let mut row = self.base_metrics_row(record, &service_name, &resource_attributes_json, scope_name, scope_version, &scope_attributes_json, &metric_name, &metric_description, &metric_unit, "Gauge"); + let mut row = self.base_metrics_row( + record, + &service_name, + &resource_attributes_json, + scope_name, + scope_version, + &scope_attributes_json, + &metric_name, + &metric_description, + &metric_unit, + "Gauge", + ); row.metric_value_number = dp.value.as_ref().and_then(number_data_point_value_f64); row.timestamp_unix_ns = Some(dp.time_unix_nano.max(record.timestamp_unix_ns)); row.start_time_unix_ns = zero_is_none(dp.start_time_unix_nano); @@ -279,7 +286,18 @@ impl ParquetExporter { } MetricData::Sum(sum) => { for dp in &sum.data_points { - let mut row = self.base_metrics_row(record, &service_name, &resource_attributes_json, scope_name, scope_version, &scope_attributes_json, &metric_name, &metric_description, &metric_unit, "Sum"); + let mut row = self.base_metrics_row( + record, + &service_name, + &resource_attributes_json, + scope_name, + scope_version, + &scope_attributes_json, + &metric_name, + &metric_description, + &metric_unit, + "Sum", + ); row.metric_value_number = dp.value.as_ref().and_then(number_data_point_value_f64); row.timestamp_unix_ns = Some(dp.time_unix_nano.max(record.timestamp_unix_ns)); row.start_time_unix_ns = zero_is_none(dp.start_time_unix_nano); @@ -291,7 +309,18 @@ impl ParquetExporter { } MetricData::Histogram(hist) => { for dp in &hist.data_points { - let mut row = self.base_metrics_row(record, &service_name, &resource_attributes_json, scope_name, scope_version, &scope_attributes_json, &metric_name, &metric_description, &metric_unit, "Histogram"); + let mut row = self.base_metrics_row( + record, + &service_name, + &resource_attributes_json, + scope_name, + scope_version, + &scope_attributes_json, + &metric_name, + &metric_description, + &metric_unit, + "Histogram", + ); row.timestamp_unix_ns = Some(dp.time_unix_nano.max(record.timestamp_unix_ns)); row.start_time_unix_ns = zero_is_none(dp.start_time_unix_nano); row.metric_value_count = Some(dp.count); @@ -303,7 +332,18 @@ impl ParquetExporter { } MetricData::ExponentialHistogram(ehist) => { for dp in &ehist.data_points { - let mut row = self.base_metrics_row(record, &service_name, &resource_attributes_json, scope_name, scope_version, &scope_attributes_json, &metric_name, &metric_description, &metric_unit, "ExponentialHistogram"); + let mut row = self.base_metrics_row( + record, + &service_name, + &resource_attributes_json, + scope_name, + scope_version, + &scope_attributes_json, + &metric_name, + &metric_description, + &metric_unit, + "ExponentialHistogram", + ); row.timestamp_unix_ns = Some(dp.time_unix_nano.max(record.timestamp_unix_ns)); row.start_time_unix_ns = zero_is_none(dp.start_time_unix_nano); row.metric_value_count = Some(dp.count); @@ -315,7 +355,18 @@ impl ParquetExporter { } MetricData::Summary(summary) => { for dp in &summary.data_points { - let mut row = self.base_metrics_row(record, &service_name, &resource_attributes_json, scope_name, scope_version, &scope_attributes_json, &metric_name, &metric_description, &metric_unit, "Summary"); + let mut row = self.base_metrics_row( + record, + &service_name, + &resource_attributes_json, + scope_name, + scope_version, + &scope_attributes_json, + &metric_name, + &metric_description, + &metric_unit, + "Summary", + ); row.timestamp_unix_ns = Some(dp.time_unix_nano.max(record.timestamp_unix_ns)); row.start_time_unix_ns = zero_is_none(dp.start_time_unix_nano); row.metric_value_count = Some(dp.count); @@ -327,7 +378,18 @@ impl ParquetExporter { } } else { // Metric with no data: emit one row with metadata only - let row = self.base_metrics_row(record, &service_name, &resource_attributes_json, scope_name, scope_version, &scope_attributes_json, &metric_name, &metric_description, &metric_unit, "Unknown"); + let row = self.base_metrics_row( + record, + &service_name, + &resource_attributes_json, + scope_name, + scope_version, + &scope_attributes_json, + &metric_name, + &metric_description, + &metric_unit, + "Unknown", + ); self.rows.push(row); } } @@ -351,7 +413,7 @@ impl ParquetExporter { let request = match ExportTraceServiceRequest::decode(payload) { Ok(request) => request, Err(err) => { - return self.fail_status(LJX_EXPORT_STATUS_ERROR, format!("failed to decode OTLP traces payload at seq {}: {err}", record.seq)) + return self.fail_status(LJX_EXPORT_STATUS_ERROR, format!("failed to decode OTLP traces payload at seq {}: {err}", record.seq)); } }; @@ -774,11 +836,7 @@ fn schema() -> SchemaRef { fn validate_host(host: &LjxExportHostV1) -> Result<(), String> { if host.struct_size < std::mem::size_of::() as u32 { - return Err(format!( - "host struct_size {} is smaller than plugin ABI expects {}", - host.struct_size, - std::mem::size_of::() - )); + return Err(format!("host struct_size {} is smaller than plugin ABI expects {}", host.struct_size, std::mem::size_of::())); } Ok(()) } @@ -808,11 +866,7 @@ fn abi_bytes<'a>(value: LjxAbiBytes) -> Result<&'a [u8], String> { } fn status_for_message(message: &str) -> i32 { - if message.contains("host callback") || message.contains("flush host output") { - LJX_EXPORT_STATUS_IO - } else { - LJX_EXPORT_STATUS_ERROR - } + if message.contains("host callback") || message.contains("flush host output") { LJX_EXPORT_STATUS_IO } else { LJX_EXPORT_STATUS_ERROR } } fn zero_is_none(value: u64) -> Option { @@ -923,10 +977,8 @@ fn attrs_to_json(attrs: &[KeyValue]) -> Option { if attrs.is_empty() { return None; } - let mut pairs = attrs - .iter() - .filter_map(|attr| attr.value.as_ref().and_then(any_value_to_json).map(|value| (attr.key.clone(), value))) - .collect::>(); + let mut pairs = + attrs.iter().filter_map(|attr| attr.value.as_ref().and_then(any_value_to_json).map(|value| (attr.key.clone(), value))).collect::>(); if pairs.is_empty() { return None; } diff --git a/tests/ljx_export.rs b/tests/ljx_export.rs index 1b0ff5e..911e0fa 100644 --- a/tests/ljx_export.rs +++ b/tests/ljx_export.rs @@ -44,7 +44,9 @@ fn ljx_exports_cpp_demo_to_parquet_and_preserves_rows() -> io::Result<()> { actual.iter().filter_map(|row| row.service_name.clone()).collect::>(), expected.iter().filter_map(|row| row.service_name.clone()).collect::>() ); - assert!(actual.iter().all(|row| row.body_kind == Some("string".to_string()) || row.body_kind == Some("empty".to_string()) || row.body_json.is_some())); + assert!( + actual.iter().all(|row| row.body_kind == Some("string".to_string()) || row.body_kind == Some("empty".to_string()) || row.body_json.is_some()) + ); Ok(()) } @@ -449,11 +451,7 @@ fn encode_metrics_request(service_name: Option<&str>) -> io::Result> { let resource_metrics = ResourceMetrics { resource: Some(resource), - scope_metrics: vec![ScopeMetrics { - scope: None, - metrics, - schema_url: String::new(), - }], + scope_metrics: vec![ScopeMetrics { scope: None, metrics, schema_url: String::new() }], schema_url: String::new(), }; @@ -512,11 +510,7 @@ fn encode_traces_request(service_name: Option<&str>) -> io::Result> { let resource_spans = ResourceSpans { resource: Some(resource), - scope_spans: vec![ScopeSpans { - scope: None, - spans, - schema_url: String::new(), - }], + scope_spans: vec![ScopeSpans { scope: None, spans, schema_url: String::new() }], schema_url: String::new(), }; From 4618592987b44afc37321b2398bad3f36d3039f5 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:05:12 +0200 Subject: [PATCH 11/21] Update demo doc --- demo/benchmark-clib/README.md | 81 ++++++++++++++++++++++++++--------- 1 file changed, 60 insertions(+), 21 deletions(-) diff --git a/demo/benchmark-clib/README.md b/demo/benchmark-clib/README.md index a302922..712e3c5 100644 --- a/demo/benchmark-clib/README.md +++ b/demo/benchmark-clib/README.md @@ -8,28 +8,63 @@ Reference: [`demo/cpp-shared-lib`](../cpp-shared-lib) ## What it measures -The driver times each call across five phases and prints a table with real -numbers (mean, p50, p95, p99, min, max) plus an `index` column — the improvement -factor `per-connection mean / row mean` (baseline = per-connection; the +The driver prints one table per transport (OTLP/gRPC, and OTLP/HTTP when an HTTP +endpoint is given). Each table times these phases with real numbers (mean, p50, +p95, p99, min, max) plus an `index` column — the improvement factor +`per-connection mean / row mean` (baseline = that transport's per-connection; the `logjet file` row's index is a no-network reference floor): 1. **logjet file (`LogjetWriter::push`)** — appending one record straight to a - `.logjet` file. No network. Isolates the storage/format layer. -2. **backend OTLP/gRPC (per-connection)** — one `lj_logger_log()` send to `ljd`. - This is the slow path: a fresh connection per record. -3. **backend OTLP/gRPC (reuse)** — one `lj_logger_log_reuse()` send, reusing a - persistent gRPC channel (Ticket 1). -4. **backend OTLP/gRPC (batch=N)** — `lj_logger_log_batch()` sending N records in - one request over the reused channel (Ticket 2). Reported per-record amortized. -5. **backend OTLP/gRPC (async enqueue)** — `lj_logger_log_async()` hands the send - to a background runtime and returns immediately (Ticket 3). The row is the + `.logjet` file. No network. Isolates the storage/format layer (gRPC table only). +2. **backend (per-connection)** — one `lj_logger_log()` send to `ljd`. The slow + path: a fresh connection per record. +3. **backend (reuse)** — one `lj_logger_log_reuse()` send, reusing a persistent + gRPC channel / HTTP keep-alive connection (Tickets 1, 4). +4. **backend (batch=N)** — `lj_logger_log_batch()` sending N records in one request + over the reused connection (Tickets 2, 4). Reported per-record amortized. +5. **backend (async enqueue)** — `lj_logger_log_async()` hands the send to a + background runtime and returns immediately (Tickets 3, 4). The row is the caller-thread enqueue cost; the demo then calls `lj_logger_flush()` and prints the async error/dropped counters. -This makes the finding explicit: the file write is cheap (µs); the -per-connection backend send is the expensive part (~ms); connection reuse helps, -batching brings the per-record cost down toward the file-write cost, and async -removes the network round-trip from the caller thread entirely. +This makes the finding explicit: the file write is cheap (µs); the per-connection +backend send is the expensive part; connection reuse helps, batching brings the +per-record cost down toward the file-write cost, and async removes the network +round-trip from the caller thread entirely. HTTP reuse uses a keep-alive +connection pool (HTTP/1.1 can't multiplex, so concurrency uses several pooled +connections, bounded by backpressure). + +## Columns (in plain terms) + +Each number is measured over the messages sent in that row. Times auto-scale: +`ns` < `us` < `ms` < `s` (smaller is faster). + +- **calls** — how many log messages this row sent. +- **total** — all the per-message times added together (how long the row took). +- **mean** — the average time for one message. +- **p50** — the middle time: half the messages were faster, half slower (median). +- **p95** — almost-worst: only about 5 of every 100 messages were slower (95th percentile). +- **p99** — worst cases: only about 1 of every 100 messages was slower (99th percentile / the occasional hiccup). +- **min** — the single fastest message. +- **max** — the single slowest message (worst hiccup). +- **index** — how many times faster this row is than the slow `per-connection` row. `1.0x` = the baseline, `2.0x` = twice as fast, `48x` = forty-eight times faster. + +## Notes (in plain terms) + +- **index baseline** — every row is compared to the slow original way (a brand-new + connection for every single message). The `logjet file` row uses no network, so + it isn't a fair race — treat its index as "the fastest anything could ever be," + not a real speed-up. +- **batch row** — batching sends many messages in one shipment, so the row shows the + cost *per message* (one shipment's time split across its messages). The note also + prints how long one whole shipment actually took. +- **async row** — "async" hands the message off and carries on without waiting for + the network, so the number is just the tiny hand-off cost. The note also prints + how long we waited at the end for everything to finish (**flush**), how many + **failed** to send, and how many were **thrown away** because messages were + produced faster than the network could send them (a safety valve). +- **reuse first/cold call** — the first `reuse` message opens the connection once + (so it's slower); every message after that reuses it. ## Async backpressure @@ -64,11 +99,15 @@ Arguments are `./run-demo.sh [count] [batch_size]`. The batch size is the number of records sent per `lj_logger_log_batch()` call (the caller controls it); change it to see how the per-record amortized cost in the `batch=N` row moves. -The script builds `ljd`, `liblogjet`, and the driver, starts file-backed `ljd` -on `127.0.0.1:4317`, runs the benchmark, prints the table, and stops `ljd`. +The script builds `ljd`, `liblogjet`, and the driver, starts two file-backed +`ljd` instances (OTLP/gRPC on `127.0.0.1:4317`, OTLP/HTTP on `127.0.0.1:4318`), +runs the benchmark (gRPC table then HTTP table), and stops both. + +The driver itself takes `benchmark-clib +[http_endpoint]`; the HTTP table is printed only when an HTTP endpoint is given. ## Extending -Reuse (Ticket 1), batching (Ticket 2), and async (Ticket 3) rows are in place. -When further ABI lands, add a phase that calls the new symbol and a row to the -table; the harness is structured for it. +Reuse (Ticket 1), batching (Ticket 2), async (Ticket 3), and HTTP keep-alive +(Ticket 4) rows are in place. When further ABI lands, add a phase that calls the +new symbol and a row to the table; the harness is structured for it. From 4cbc379bb0124e16399a0ecec4beeebf9a188019 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:05:44 +0200 Subject: [PATCH 12/21] Update benchmark demo with HTTP proto --- demo/benchmark-clib/ljd-http.conf | 8 ++ demo/benchmark-clib/main.rs | 133 +++++++++++++++++++++--------- demo/benchmark-clib/run-demo.sh | 15 +++- 3 files changed, 116 insertions(+), 40 deletions(-) create mode 100644 demo/benchmark-clib/ljd-http.conf diff --git a/demo/benchmark-clib/ljd-http.conf b/demo/benchmark-clib/ljd-http.conf new file mode 100644 index 0000000..27d6d2a --- /dev/null +++ b/demo/benchmark-clib/ljd-http.conf @@ -0,0 +1,8 @@ +output: file +file.path: ./logs +file.size: 1048576 +file.name: benchmark-clib-http.logjet +ingest.protocol: otlp-http +ingest.listen: 127.0.0.1:4318 +ingest.max-clients: 2048 +replay.listen: 127.0.0.1:7003 diff --git a/demo/benchmark-clib/main.rs b/demo/benchmark-clib/main.rs index 39ac5c4..bd37519 100644 --- a/demo/benchmark-clib/main.rs +++ b/demo/benchmark-clib/main.rs @@ -13,24 +13,27 @@ //! the exported C ABI symbols of `liblogjet` (the same code a C/C++ caller //! exercises through the shared library). -use std::ffi::{CStr, CString}; +use std::ffi::{CStr, CString, c_char}; use std::fs::File; use std::io::{BufWriter, Write}; use std::ptr; use std::time::{Instant, SystemTime, UNIX_EPOCH}; use liblogjet::{ - LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, - lj_logger_log, lj_logger_log_async, lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, + LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, lj_logger_log, lj_logger_log_async, + lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, lj_logger_new_http, lj_logger_set_backpressure, }; use logjet::{LogjetWriter, RecordType}; const LJ_ATTR_STRING: i32 = 0; +const LJ_BACKPRESSURE_BLOCK: i32 = 2; +const HTTP_ASYNC_CAPACITY: usize = 64; const SEVERITY_INFO: i32 = 9; const TIMEOUT_MS: u64 = 2000; const PAYLOAD_LEN: usize = 200; type LogFn = unsafe extern "C" fn(*mut lj_logger, *const LjLogRecord) -> bool; +type NewFn = unsafe extern "C" fn(*const c_char, *const c_char, u64) -> *mut lj_logger; struct Stats { count: usize, @@ -48,8 +51,13 @@ fn main() { let endpoint = args.next().unwrap_or_else(|| "127.0.0.1:4317".to_string()); let count: usize = args.next().and_then(|value| value.parse().ok()).filter(|n| *n > 0).unwrap_or(1000); let batch_size: usize = args.next().and_then(|value| value.parse().ok()).filter(|n| *n > 0).unwrap_or(100); + let http_endpoint = args.next().filter(|value| !value.is_empty()); - println!("benchmark-clib: {count} records per phase, batch={batch_size}, endpoint {endpoint}\n"); + println!("benchmark-clib: {count} records per phase, batch={batch_size}, gRPC endpoint {endpoint}"); + match &http_endpoint { + Some(http) => println!("HTTP endpoint {http}\n"), + None => println!("(HTTP phases skipped; pass an HTTP endpoint as the 4th argument)\n"), + } let file_samples = match run_file_phase(count) { Ok(samples) => samples, @@ -89,70 +97,116 @@ fn main() { scope_attrs_len: 0, }; - let per_connection = match unsafe { run_backend_phase(&endpoint_c, &service_c, &mut record, count, lj_logger_log) } { + let file_stats = summarize(file_samples); + + run_and_print_transport("gRPC", lj_logger_new_grpc, &endpoint_c, &endpoint, &service_c, &mut record, count, batch_size, Some(&file_stats)); + + if let Some(http) = http_endpoint { + let http_c = CString::new(http.as_str()).expect("http endpoint has interior NUL"); + run_and_print_transport("HTTP", lj_logger_new_http, &http_c, &http, &service_c, &mut record, count, batch_size, None); + } + + print_legend(); +} + +fn print_legend() { + println!("Columns:"); + println!(" calls how many log messages this test sent"); + println!(" total all the per-message times added together"); + println!(" mean average time for one message"); + println!(" p50 middle time: half the messages were faster, half slower (median)"); + println!(" p95 almost-worst: only ~5 of 100 messages were slower (95th percentile)"); + println!(" p99 worst cases: only ~1 of 100 messages was slower (99th percentile)"); + println!(" min the single fastest message"); + println!(" max the single slowest message (worst hiccup)"); + println!(" index how many times faster than per-connection (1.0x = baseline; higher is better)"); + println!("Units: ns < us < ms < s (smaller is faster)."); +} + +#[allow(clippy::too_many_arguments)] +fn run_and_print_transport( + proto: &str, + new_fn: NewFn, + endpoint: &CStr, + endpoint_str: &str, + service: &CStr, + record: &mut LjLogRecord, + count: usize, + batch_size: usize, + file_stats: Option<&Stats>, +) { + let per_connection = match unsafe { run_backend_phase(endpoint, service, record, count, new_fn, lj_logger_log) } { Ok(result) => result, Err(err) => { - eprintln!("per-connection backend phase failed: {err}"); - eprintln!("is ljd listening on {endpoint}? start it with run-demo.sh"); + eprintln!("{proto} per-connection phase failed: {err}"); + eprintln!("is ljd listening on {endpoint_str}? start it with run-demo.sh"); std::process::exit(1); } }; - - let reuse = match unsafe { run_backend_phase(&endpoint_c, &service_c, &mut record, count, lj_logger_log_reuse) } { + let reuse = match unsafe { run_backend_phase(endpoint, service, record, count, new_fn, lj_logger_log_reuse) } { Ok(result) => result, Err(err) => { - eprintln!("reuse backend phase failed: {err}"); + eprintln!("{proto} reuse phase failed: {err}"); std::process::exit(1); } }; - - let batch = match unsafe { run_batch_phase(&endpoint_c, &service_c, &record, count, batch_size) } { + let batch = match unsafe { run_batch_phase(endpoint, service, record, count, batch_size, new_fn) } { Ok(result) => result, Err(err) => { - eprintln!("batch backend phase failed: {err}"); + eprintln!("{proto} batch phase failed: {err}"); std::process::exit(1); } }; - - let async_phase = match unsafe { run_async_phase(&endpoint_c, &service_c, &record, count) } { + let async_backpressure = if proto == "HTTP" { Some((LJ_BACKPRESSURE_BLOCK, HTTP_ASYNC_CAPACITY)) } else { None }; + let async_phase = match unsafe { run_async_phase(endpoint, service, record, count, new_fn, async_backpressure) } { Ok(result) => result, Err(err) => { - eprintln!("async backend phase failed: {err}"); + eprintln!("{proto} async phase failed: {err}"); std::process::exit(1); } }; - let file_stats = summarize(file_samples); let per_connection_stats = summarize(per_connection.samples); let reuse_cold = reuse.cold_first; let reuse_stats = summarize(reuse.samples); let raw_batch_mean = batch.raw_batch_mean; let batch_stats = summarize(batch.samples); - let batch_label = format!("backend OTLP/gRPC (batch={batch_size})"); let async_stats = summarize(async_phase.samples); + let pc_label = format!("backend OTLP/{proto} (per-connection)"); + let reuse_label = format!("backend OTLP/{proto} (reuse)"); + let batch_label = format!("backend OTLP/{proto} (batch={batch_size})"); + let async_label = format!("backend OTLP/{proto} (async enqueue)"); + let baseline = per_connection_stats.mean; - print_table( - &[ - ("logjet file (LogjetWriter::push)", &file_stats), - ("backend OTLP/gRPC (per-connection)", &per_connection_stats), - ("backend OTLP/gRPC (reuse)", &reuse_stats), - (batch_label.as_str(), &batch_stats), - ("backend OTLP/gRPC (async enqueue)", &async_stats), - ], - baseline, - ); + let mut rows: Vec<(&str, &Stats)> = Vec::new(); + if let Some(file_stats) = file_stats { + rows.push(("logjet file (LogjetWriter::push)", file_stats)); + } + rows.push((pc_label.as_str(), &per_connection_stats)); + rows.push((reuse_label.as_str(), &reuse_stats)); + rows.push((batch_label.as_str(), &batch_stats)); + rows.push((async_label.as_str(), &async_stats)); + println!("== OTLP/{proto} =="); + print_table(&rows, baseline); println!(); - println!("index = per-connection mean / row mean (baseline = per-connection; logjet file is a no-network reference)"); - println!("note: batch row is per-record amortized; raw per-batch-call mean: {}", fmt_dur(raw_batch_mean)); + println!("index = how many times faster than per-connection (baseline 1.0x; higher is better)"); + if file_stats.is_some() { + println!("note: 'logjet file' has no network, so its index is a best-case floor, not a real speed-up"); + } + println!( + "note: 'batch' shows time per message ({batch_size} sent in one shipment, split across them); one full shipment took {} on average", + fmt_dur(raw_batch_mean) + ); println!( - "note: async row is the caller-thread enqueue cost (fire-and-forget); flush: {}, errors: {}, dropped: {}", + "note: 'async' is only the hand-off cost (we don't wait for the network); waited {} at the end for all to finish; {} failed to send, {} thrown away (sending slower than produced)", fmt_dur(async_phase.flush_ns), async_phase.errors, async_phase.dropped, ); - println!("reuse first/cold call (one-time connect): {}", fmt_dur(reuse_cold)); + println!("note: the first 'reuse' message opens the connection once ({}); every message after reuses it", fmt_dur(reuse_cold)); + println!(); } fn run_file_phase(count: usize) -> std::io::Result> { @@ -182,8 +236,8 @@ struct BackendResult { cold_first: f64, } -unsafe fn run_backend_phase(endpoint: &CStr, service: &CStr, record: &mut LjLogRecord, count: usize, log_fn: LogFn) -> Result { - let logger = unsafe { lj_logger_new_grpc(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; +unsafe fn run_backend_phase(endpoint: &CStr, service: &CStr, record: &mut LjLogRecord, count: usize, new_fn: NewFn, log_fn: LogFn) -> Result { + let logger = unsafe { new_fn(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; if logger.is_null() { return Err(last_error()); } @@ -235,8 +289,8 @@ fn clone_record(template: &LjLogRecord) -> LjLogRecord { } } -unsafe fn run_batch_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, batch_size: usize) -> Result { - let logger = unsafe { lj_logger_new_grpc(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; +unsafe fn run_batch_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, batch_size: usize, new_fn: NewFn) -> Result { + let logger = unsafe { new_fn(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; if logger.is_null() { return Err(last_error()); } @@ -287,11 +341,14 @@ struct AsyncResult { dropped: u64, } -unsafe fn run_async_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize) -> Result { - let logger = unsafe { lj_logger_new_grpc(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; +unsafe fn run_async_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, new_fn: NewFn, backpressure: Option<(i32, usize)>) -> Result { + let logger = unsafe { new_fn(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; if logger.is_null() { return Err(last_error()); } + if let Some((model, capacity)) = backpressure { + unsafe { lj_logger_set_backpressure(logger, model, capacity) }; + } let mut record = clone_record(template); let mut samples = Vec::with_capacity(count); diff --git a/demo/benchmark-clib/run-demo.sh b/demo/benchmark-clib/run-demo.sh index 435b76f..b282e81 100755 --- a/demo/benchmark-clib/run-demo.sh +++ b/demo/benchmark-clib/run-demo.sh @@ -7,7 +7,9 @@ TARGET_DIR="$ROOT_DIR/target/debug" LJD="$TARGET_DIR/ljd" BENCH="$TARGET_DIR/benchmark-clib" CONFIG="$SCRIPT_DIR/ljd.conf" +CONFIG_HTTP="$SCRIPT_DIR/ljd-http.conf" ENDPOINT="127.0.0.1:4317" +ENDPOINT_HTTP="127.0.0.1:4318" COUNT="${1:-1000}" BATCH_SIZE="${2:-100}" @@ -16,12 +18,21 @@ cargo build -p ljd -p liblogjet -p otlp-demo --bin benchmark-clib mkdir -p "$SCRIPT_DIR/logs" +# Run from the demo dir so ljd resolves the relative file.path (./logs), and start +# ljd directly (no subshell) so the trap can actually kill it. +cd "$SCRIPT_DIR" + echo "starting ljd with file-backed OTLP/gRPC ingest on $ENDPOINT" -(cd "$SCRIPT_DIR" && "$LJD" --config "$CONFIG" serve) & +"$LJD" --config "$CONFIG" serve & LJD_PID=$! +echo "starting ljd with file-backed OTLP/HTTP ingest on $ENDPOINT_HTTP" +"$LJD" --config "$CONFIG_HTTP" serve & +LJD_HTTP_PID=$! + cleanup() { kill "${LJD_PID:-}" 2>/dev/null || true + kill "${LJD_HTTP_PID:-}" 2>/dev/null || true } trap cleanup EXIT INT TERM @@ -29,4 +40,4 @@ sleep 1 echo "running benchmark ($COUNT records per phase, batch=$BATCH_SIZE)" echo -"$BENCH" "$ENDPOINT" "$COUNT" "$BATCH_SIZE" +"$BENCH" "$ENDPOINT" "$COUNT" "$BATCH_SIZE" "$ENDPOINT_HTTP" From 2b36299794280b091a368d33e4e5ad464f163d2b Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:06:31 +0200 Subject: [PATCH 13/21] Use async/batch/conn-reuse modes in shared lib example --- demo/cpp-shared-lib/README.md | 22 ++-- demo/cpp-shared-lib/cpp-logger.cpp | 181 ++++++++++++++++------------- demo/cpp-shared-lib/ljd-http.conf | 8 ++ demo/cpp-shared-lib/run-demo.sh | 33 ++++-- 4 files changed, 145 insertions(+), 99 deletions(-) create mode 100644 demo/cpp-shared-lib/ljd-http.conf diff --git a/demo/cpp-shared-lib/README.md b/demo/cpp-shared-lib/README.md index e7e8bde..f73ca0c 100644 --- a/demo/cpp-shared-lib/README.md +++ b/demo/cpp-shared-lib/README.md @@ -1,11 +1,12 @@ # C++ Shared Library Demo This demo shows one C++ process loading a Rust shared library and sending OTLP -logs into `ljd` over gRPC. +logs into `ljd` over both gRPC and HTTP, exercising the per-connection, reuse, +batch, and async send paths. The path is: -`C++ appliance -> liblogjet.so -> OTLP/gRPC -> ljd -> .logjet file -> ljx view` +`C++ appliance -> liblogjet.so -> OTLP/gRPC or OTLP/HTTP -> ljd -> .logjet file -> ljx view` ## Build First @@ -23,7 +24,8 @@ example on demand. From this directory: ```bash -./run-demo.sh +./run-demo.sh # 25 records per phase (default) +./run-demo.sh 100 # custom record count ``` ## What It Does @@ -31,15 +33,19 @@ From this directory: The script: 1. builds the example C++ logger -2. starts file-backed `ljd` on `127.0.0.1:4317` +2. starts two file-backed `ljd` instances: OTLP/gRPC on `127.0.0.1:4317` and OTLP/HTTP on `127.0.0.1:4318` 3. loads `liblogjet.so` through `dlopen` -4. sends 25 OTLP log records from C++ by default -5. opens `ljx view` on the resulting `./logs/cpp-demo.logjet` +4. runs the C++ logger once per transport, each exercising four send paths: + - **per-connection** (`lj_logger_log`) + - **reuse** (`lj_logger_log_reuse`) + - **batch** (`lj_logger_log_batch`, many records in one request) + - **async** (`lj_logger_log_async` with `lj_logger_set_backpressure` + `lj_logger_flush`, then prints the async counters) +5. opens `ljx view` on `./logs/cpp-demo.logjet` (gRPC), then on `./logs/cpp-demo-http.logjet` (HTTP) ## Notes -- the library now supports both OTLP/HTTP and OTLP/gRPC constructors -- this demo specifically uses OTLP/gRPC +- the demo runs both OTLP/gRPC and OTLP/HTTP; the C++ source picks the constructor (`lj_logger_new_grpc` / `lj_logger_new_http`) from its 4th argument +- reuse/batch/async work over both transports (HTTP uses a keep-alive connection pool) - the FFI API is intentionally small: endpoint, service name, timestamp, severity, message body, and string attributes - those key/value pairs become OTLP `LogRecord.attributes`, which is the standard OTel metadata field for log records - if the appliance already has JSON metadata, the better long-term shape is to flatten that JSON into separate attributes where possible; a raw JSON blob can still be sent as one string attribute when needed diff --git a/demo/cpp-shared-lib/cpp-logger.cpp b/demo/cpp-shared-lib/cpp-logger.cpp index 11e31bb..8901d4c 100644 --- a/demo/cpp-shared-lib/cpp-logger.cpp +++ b/demo/cpp-shared-lib/cpp-logger.cpp @@ -7,7 +7,6 @@ #include #include #include -#include #include namespace { @@ -18,6 +17,10 @@ using new_http_fn = lj_logger *(*)(const char *, const char *, std::uint64_t); using new_grpc_fn = lj_logger *(*)(const char *, const char *, std::uint64_t); using free_fn = void (*)(lj_logger *); using log_fn = bool (*)(lj_logger *, const lj_log_record *); +using batch_fn = bool (*)(lj_logger *, const lj_log_record *, std::size_t); +using set_bp_fn = bool (*)(lj_logger *, std::int32_t, std::size_t); +using flush_fn = bool (*)(lj_logger *, std::uint64_t); +using counter_fn = std::uint64_t (*)(lj_logger *); struct api { version_fn version; @@ -26,15 +29,32 @@ struct api { new_grpc_fn new_grpc; free_fn free_logger; log_fn log_record; + log_fn log_reuse; + batch_fn log_batch; + log_fn log_async; + set_bp_fn set_backpressure; + flush_fn flush; + counter_fn async_errors; + counter_fn async_dropped; + counter_fn async_inflight; }; -std::int32_t info_severity() { - return LJ_SEVERITY_INFO; -} +const std::vector kQuotes = { + "Bender promised a classy fun park financed mostly by blackjack.", + "Fry pressed the glowing button because hesitation felt off-brand.", + "Leela requested a routine delivery and got stylish chaos instead.", + "The Professor called this outage a perfectly normal science moment.", + "Zoidberg celebrated because nobody had blamed him yet.", + "Hermes filed the disaster under efficient bureaucratic progress.", + "Amy said the ship felt stable, which worried everyone instantly.", + "Nibbler stared into the void like it owed him money.", + "Scruffy fixed the panel and resumed mopping without commentary.", + "Calculon demanded better lighting for the emergency landing.", +}; -const char *pick(const std::vector &values, std::mt19937 &rng) { - std::uniform_int_distribution dist(0, values.size() - 1); - return values[dist(rng)]; +std::string pick_message(std::mt19937 &rng) { + std::uniform_int_distribution dist(0, kQuotes.size() - 1); + return kQuotes[dist(rng)]; } std::uint64_t unix_time_nanos() { @@ -61,15 +81,47 @@ api load_api(void *handle) { reinterpret_cast(must_symbol(handle, "lj_logger_new_grpc")), reinterpret_cast(must_symbol(handle, "lj_logger_free")), reinterpret_cast(must_symbol(handle, "lj_logger_log")), + reinterpret_cast(must_symbol(handle, "lj_logger_log_reuse")), + reinterpret_cast(must_symbol(handle, "lj_logger_log_batch")), + reinterpret_cast(must_symbol(handle, "lj_logger_log_async")), + reinterpret_cast(must_symbol(handle, "lj_logger_set_backpressure")), + reinterpret_cast(must_symbol(handle, "lj_logger_flush")), + reinterpret_cast(must_symbol(handle, "lj_logger_async_errors")), + reinterpret_cast(must_symbol(handle, "lj_logger_async_dropped")), + reinterpret_cast(must_symbol(handle, "lj_logger_async_inflight")), }; } +// Sends one record one at a time via the given function (log / reuse / async). +// Safe to use local strings: the library reads them before the call returns +// (async builds its request synchronously, then sends in the background). +void send_one_at_a_time(const api &lib, lj_logger *logger, log_fn send, const char *phase, int count, std::mt19937 &rng) { + int ok = 0; + for (int i = 0; i < count; ++i) { + const std::string message = pick_message(rng); + const lj_attribute attrs[] = { + {"appliance.kind", "cpp-demo"}, + {"phase", phase}, + }; + const lj_log_record record{ + unix_time_nanos(), LJ_SEVERITY_INFO, "INFO", message.c_str(), attrs, sizeof(attrs) / sizeof(attrs[0]), + }; + if (send(logger, &record)) { + ++ok; + } else { + std::cerr << " " << phase << " send failed: " << lib.error_message() << "\n"; + } + } + std::cout << " [" << phase << "] accepted " << ok << "/" << count << "\n"; +} + } // namespace int main(int argc, char **argv) { const std::string so_path = argc > 1 ? argv[1] : "./liblogjet.so"; const std::string endpoint = argc > 2 ? argv[2] : "127.0.0.1:4317"; const int message_count = argc > 3 ? std::atoi(argv[3]) : 25; + const std::string protocol = argc > 4 ? argv[4] : "grpc"; void *handle = dlopen(so_path.c_str(), RTLD_NOW | RTLD_LOCAL); if (handle == nullptr) { @@ -78,92 +130,57 @@ int main(int argc, char **argv) { } const api lib = load_api(handle); - std::cout << "loaded liblogjet version " << lib.version() << "\n"; + std::cout << "loaded liblogjet version " << lib.version() << " (transport: " << protocol << ", endpoint: " << endpoint << ")\n"; - std::mt19937 rng(std::random_device{}()); - const std::vector characters = { - "Bender", "Fry", "Leela", "Professor Farnsworth", "Zoidberg", - "Amy", "Hermes", "Nibbler", "Scruffy", "Calculon", - }; - const std::vector locations = { - "Planet Express", "New New York", "The Moon", "Mars University", - "Robot Hell", "Slurm factory", "Omicron Persei 8", "Bender's fun park", - }; - const std::vector attractions = { - "blackjack dome", "dark matter coaster", "hooker-bot lounge", - "slurm chute", "robot petting zoo", "delivery cannon", - }; - const std::vector moods = { - "greedy", "heroic", "dramatic", "sleepy", - "chaotic", "optimistic", "hungry", "unbothered", - }; - const std::vector schemes = { - "casino expansion", "fun park launch", "delivery detour", - "robot uprising rehearsal", "slurm promotion", "budget evaporation", - }; - const std::vector quotes = { - "Bender promised a classy fun park financed mostly by blackjack.", - "Fry pressed the glowing button because hesitation felt off-brand.", - "Leela requested a routine delivery and got stylish chaos instead.", - "The Professor called this outage a perfectly normal science moment.", - "Zoidberg celebrated because nobody had blamed him yet.", - "Hermes filed the disaster under efficient bureaucratic progress.", - "Amy said the ship felt stable, which worried everyone instantly.", - "Nibbler stared into the void like it owed him money.", - "Scruffy fixed the panel and resumed mopping without commentary.", - "Calculon demanded better lighting for the emergency landing.", - "Bender unveiled a premium attraction featuring hooker-bots and bad odds.", - "The crew found a shortcut through poor planning and dark matter.", - "Mission control agreed this was still cheaper than preparation.", - "Someone ordered suspicious robot bees and called it innovation.", - "The delivery manifest now includes one crate of dramatic overreaction.", - }; - - lj_logger *logger = lib.new_grpc(endpoint.c_str(), "cpp-appliance", 2000); + lj_logger *logger = nullptr; + if (protocol == "http") { + logger = lib.new_http(endpoint.c_str(), "cpp-appliance", 2000); + } else { + logger = lib.new_grpc(endpoint.c_str(), "cpp-appliance", 2000); + } if (logger == nullptr) { - std::cerr << "lj_logger_new_grpc failed: " << lib.error_message() << "\n"; + std::cerr << "logger creation failed: " << lib.error_message() << "\n"; dlclose(handle); return 1; } - for (int index = 1; index <= message_count; ++index) { - const std::string sequence = std::to_string(index); - const std::string character = pick(characters, rng); - const std::string location = pick(locations, rng); - const std::string attraction = pick(attractions, rng); - const std::string mood = pick(moods, rng); - const std::string scheme = pick(schemes, rng); - const std::string message = - std::string(pick(quotes, rng)) + " character=" + character + " location=" + location; - const lj_attribute attributes[] = { + std::mt19937 rng(std::random_device{}()); + const int per_phase = std::max(1, message_count / 4); + + // Phase 1: per-connection (a fresh connection per record). + send_one_at_a_time(lib, logger, lib.log_record, "per-connection", per_phase, rng); + + // Phase 2: reuse (one persistent connection). + send_one_at_a_time(lib, logger, lib.log_reuse, "reuse", per_phase, rng); + + // Phase 3: batch (one request carrying many records). + { + std::vector bodies(static_cast(per_phase)); + const lj_attribute attrs[] = { {"appliance.kind", "cpp-demo"}, - {"appliance.sequence", sequence.c_str()}, - {"character", character.c_str()}, - {"location", location.c_str()}, - {"attraction", attraction.c_str()}, - {"mood", mood.c_str()}, - {"scheme", scheme.c_str()}, - }; - const lj_log_record record{ - unix_time_nanos(), - info_severity(), - "INFO", - message.c_str(), - attributes, - sizeof(attributes) / sizeof(attributes[0]), + {"phase", "batch"}, }; - - if (!lib.log_record(logger, &record)) { - std::cerr << "lj_logger_log failed: " << lib.error_message() << "\n"; - lib.free_logger(logger); - dlclose(handle); - return 1; + std::vector records; + records.reserve(static_cast(per_phase)); + for (int i = 0; i < per_phase; ++i) { + bodies[static_cast(i)] = pick_message(rng); + records.push_back(lj_log_record{ + unix_time_nanos(), LJ_SEVERITY_INFO, "INFO", bodies[static_cast(i)].c_str(), attrs, sizeof(attrs) / sizeof(attrs[0]), + }); + } + if (lib.log_batch(logger, records.data(), records.size())) { + std::cout << " [batch] sent " << records.size() << " records in one request\n"; + } else { + std::cerr << " [batch] send failed: " << lib.error_message() << "\n"; } - - std::cout << "sent: " << message << "\n"; - std::this_thread::sleep_for(std::chrono::milliseconds(20)); } + // Phase 4: async (non-blocking; bounded by backpressure, then drained). + lib.set_backpressure(logger, LJ_BACKPRESSURE_DROP, 256); + send_one_at_a_time(lib, logger, lib.log_async, "async", per_phase, rng); + lib.flush(logger, 5000); + std::cout << " [async] errors=" << lib.async_errors(logger) << " dropped=" << lib.async_dropped(logger) << " inflight=" << lib.async_inflight(logger) << "\n"; + lib.free_logger(logger); dlclose(handle); return 0; diff --git a/demo/cpp-shared-lib/ljd-http.conf b/demo/cpp-shared-lib/ljd-http.conf new file mode 100644 index 0000000..3df3fbb --- /dev/null +++ b/demo/cpp-shared-lib/ljd-http.conf @@ -0,0 +1,8 @@ +output: file +file.path: ./logs +file.size: 1048576 +file.name: cpp-demo-http.logjet +ingest.protocol: otlp-http +ingest.listen: 127.0.0.1:4318 +ingest.max-clients: 2048 +replay.listen: 127.0.0.1:7013 diff --git a/demo/cpp-shared-lib/run-demo.sh b/demo/cpp-shared-lib/run-demo.sh index 696c79c..4fd1b74 100755 --- a/demo/cpp-shared-lib/run-demo.sh +++ b/demo/cpp-shared-lib/run-demo.sh @@ -9,7 +9,9 @@ LIB_SRC="$TARGET_DIR/libliblogjet.so" LIB_DST="$SCRIPT_DIR/liblogjet.so" CPP_SRC="$SCRIPT_DIR/cpp-logger.cpp" CPP_BIN="$SCRIPT_DIR/cpp-logger" -CONFIG="$SCRIPT_DIR/ljd.conf" +CONFIG_GRPC="$SCRIPT_DIR/ljd.conf" +CONFIG_HTTP="$SCRIPT_DIR/ljd-http.conf" +COUNT="${1:-25}" for bin in "$LJD" "$LJX" "$LIB_SRC"; do if [ ! -e "$bin" ]; then @@ -31,22 +33,35 @@ ln -sf "$LIB_SRC" "$LIB_DST" echo "building C++ example" g++ -std=c++17 -Wall -Wextra -pedantic -O2 -I"$SCRIPT_DIR/../../liblogjet/include" "$CPP_SRC" -ldl -o "$CPP_BIN" -echo "starting ljd with file-backed OTLP ingest" -"$LJD" --config "$CONFIG" serve & -LJD_PID=$! +# Run from the demo dir so ljd resolves the relative file.path (./logs). +cd "$SCRIPT_DIR" + +echo "starting ljd: OTLP/gRPC on 127.0.0.1:4317 and OTLP/HTTP on 127.0.0.1:4318" +"$LJD" --config "$CONFIG_GRPC" serve & +LJD_GRPC_PID=$! +"$LJD" --config "$CONFIG_HTTP" serve & +LJD_HTTP_PID=$! cleanup() { - kill "${LJD_PID:-}" 2>/dev/null || true + kill "${LJD_GRPC_PID:-}" 2>/dev/null || true + kill "${LJD_HTTP_PID:-}" 2>/dev/null || true } - trap cleanup EXIT INT TERM sleep 1 -echo "sending logs from C++ through liblogjet.so into ljd over OTLP/gRPC" -"$CPP_BIN" "$LIB_DST" "127.0.0.1:4317" 25 +echo +echo "=== OTLP/gRPC: per-connection, reuse, batch, async ===" +"$CPP_BIN" "$LIB_DST" "127.0.0.1:4317" "$COUNT" grpc + +echo +echo "=== OTLP/HTTP: per-connection, reuse, batch, async ===" +"$CPP_BIN" "$LIB_DST" "127.0.0.1:4318" "$COUNT" http sleep 1 -echo "opening ljx view on ./logs/cpp-demo.logjet" +echo +echo "results: ./logs/cpp-demo.logjet (gRPC) and ./logs/cpp-demo-http.logjet (HTTP)" +echo "opening ljx view on the gRPC capture (quit to open the HTTP capture)" "$LJX" view "$SCRIPT_DIR/logs/cpp-demo.logjet" +"$LJX" view "$SCRIPT_DIR/logs/cpp-demo-http.logjet" From e40e3af936c584e41a437fc1817256b36a3032e9 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:06:42 +0200 Subject: [PATCH 14/21] Update C++ integration docs --- doc/c-cpp-integration.md | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/doc/c-cpp-integration.md b/doc/c-cpp-integration.md index a374420..6beba8a 100644 --- a/doc/c-cpp-integration.md +++ b/doc/c-cpp-integration.md @@ -95,3 +95,23 @@ int main() { - attribute keys and values are currently string-only by design - richer C++ usage lives in the demo: - [`demo/cpp-shared-lib`](../demo/cpp-shared-lib) + +## Performance: connection reuse, batching, async + +`lj_logger_log` opens a fresh connection per record (simplest, most robust). For +high-rate logging, additive entry points reuse the connection and amortise the +network cost, for both gRPC and HTTP (HTTP via a keep-alive connection pool): + +- `lj_logger_log_reuse(logger, record)` — one record over a persistent connection. +- `lj_logger_log_batch(logger, records, len)` — many records in one request. +- `lj_logger_log_async(logger, record)` / `lj_logger_log_batch_async(...)` — + non-blocking; hands the send to a background runtime and returns immediately. + +Async sends are bounded by a backpressure policy +(`lj_logger_set_backpressure(logger, model, capacity)`; models +`LJ_BACKPRESSURE_UNBOUNDED` / `LJ_BACKPRESSURE_DROP` / `LJ_BACKPRESSURE_BLOCK`, +default `DROP`/1024). Drain in-flight sends with +`lj_logger_flush(logger, timeout_ms)` (also done on `lj_logger_free`), and observe +`lj_logger_async_errors` / `lj_logger_async_dropped` / `lj_logger_async_inflight`. + +A measured comparison lives in [`demo/benchmark-clib`](../demo/benchmark-clib). From f3f1af49b78d8afb059dbc831416d55a52727d1f Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:07:00 +0200 Subject: [PATCH 15/21] Add HTTP proto for batching/async --- liblogjet/src/lib.rs | 362 +++++++++++++++++++++++++++++++------------ 1 file changed, 259 insertions(+), 103 deletions(-) diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index a8e2ed9..bd3f63d 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -4,10 +4,10 @@ pub mod export; use std::cell::RefCell; use std::ffi::{CStr, CString, c_char}; -use std::io::{Read, Write}; -use std::net::{Shutdown, TcpStream}; +use std::io::{BufRead, Read, Write}; +use std::net::TcpStream; use std::sync::atomic::{AtomicU64, Ordering}; -use std::sync::{Arc, Mutex}; +use std::sync::{Arc, Mutex, OnceLock}; use std::time::Duration; use opentelemetry_proto::tonic::collector::logs::v1::{ExportLogsServiceRequest, logs_service_client::LogsServiceClient}; @@ -28,6 +28,7 @@ const LJ_BACKPRESSURE_UNBOUNDED: i32 = 0; const LJ_BACKPRESSURE_DROP: i32 = 1; const LJ_BACKPRESSURE_BLOCK: i32 = 2; const DEFAULT_BACKPRESSURE_CAPACITY: usize = 1024; +const MAX_HTTP_POOL: usize = 256; const DEFAULT_SCOPE_NAME: &str = "liblogjet"; const VERSION: &[u8] = concat!(env!("CARGO_PKG_VERSION"), "\0").as_bytes(); @@ -90,7 +91,7 @@ struct Logger { } enum Backend { - Http(HttpEndpoint), + Http(HttpClient), Grpc(GrpcClient), } @@ -103,19 +104,47 @@ struct HttpEndpoint { struct GrpcClient { runtime: Runtime, - shared: Arc, + engine: Arc, + channel: Arc, } -struct GrpcShared { +struct GrpcChannel { endpoint: String, channel: TokioMutex>, +} + +struct HttpClient { + runtime: OnceLock, + engine: Arc, + pool: Arc, +} + +struct HttpPool { + endpoint: HttpEndpoint, + idle: Mutex>, +} + +/// Backend-agnostic async send engine: backpressure, counters, and drain. +struct AsyncEngine { backpressure: Mutex, inflight: AtomicU64, - async_errors: AtomicU64, - async_dropped: AtomicU64, + errors: AtomicU64, + dropped: AtomicU64, idle: Notify, } +impl AsyncEngine { + fn new() -> Arc { + Arc::new(Self { + backpressure: Mutex::new(Backpressure { model: LJ_BACKPRESSURE_DROP, semaphore: Arc::new(Semaphore::new(DEFAULT_BACKPRESSURE_CAPACITY)) }), + inflight: AtomicU64::new(0), + errors: AtomicU64::new(0), + dropped: AtomicU64::new(0), + idle: Notify::new(), + }) + } +} + struct Backpressure { model: i32, semaphore: Arc, @@ -335,17 +364,34 @@ pub unsafe extern "C" fn lj_logger_log_batch_async(logger: *mut lj_logger, recor } } -/// Configures the async backpressure policy for a gRPC logger. +fn logger_engine(logger: &Logger) -> &Arc { + match &logger.backend { + Backend::Grpc(client) => &client.engine, + Backend::Http(client) => &client.engine, + } +} + +fn flush_logger(logger: &Logger, timeout: Duration) -> bool { + match &logger.backend { + Backend::Grpc(client) => flush_engine(&client.runtime, &client.engine, timeout), + Backend::Http(client) => match client.runtime.get() { + Some(runtime) => flush_engine(runtime, &client.engine, timeout), + None => client.engine.inflight.load(Ordering::SeqCst) == 0, + }, + } +} + +/// Configures the async backpressure policy (gRPC or HTTP). /// /// `model` is one of `LJ_BACKPRESSURE_UNBOUNDED`, `LJ_BACKPRESSURE_DROP`, or /// `LJ_BACKPRESSURE_BLOCK`. `capacity` is the maximum number of in-flight async /// sends for the bounded models (ignored for unbounded). Should be called /// before the first async send. Returns `false` (with `lj_error_message`) on -/// invalid input or for non-gRPC loggers. +/// invalid input. /// /// # Safety /// -/// `logger` must be a valid pointer returned by `lj_logger_new_grpc`. +/// `logger` must be a valid pointer returned by this library. #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_set_backpressure(logger: *mut lj_logger, model: i32, capacity: usize) -> bool { clear_last_error(); @@ -356,13 +402,6 @@ pub unsafe extern "C" fn lj_logger_set_backpressure(logger: *mut lj_logger, mode return false; } }; - let client = match &logger.inner.backend { - Backend::Grpc(client) => client, - Backend::Http(_) => { - set_last_error("backpressure applies to gRPC loggers only"); - return false; - } - }; if model != LJ_BACKPRESSURE_UNBOUNDED && model != LJ_BACKPRESSURE_DROP && model != LJ_BACKPRESSURE_BLOCK { set_last_error("invalid backpressure model"); return false; @@ -375,7 +414,7 @@ pub unsafe extern "C" fn lj_logger_set_backpressure(logger: *mut lj_logger, mode } else { capacity }; - match client.shared.backpressure.lock() { + match logger_engine(&logger.inner).backpressure.lock() { Ok(mut cfg) => { cfg.model = model; cfg.semaphore = Arc::new(Semaphore::new(capacity)); @@ -390,8 +429,7 @@ pub unsafe extern "C" fn lj_logger_set_backpressure(logger: *mut lj_logger, mode /// Blocks until all in-flight async sends complete or `timeout_ms` elapses. /// -/// Returns `true` if fully drained, `false` on timeout. HTTP loggers (which have -/// no async queue) always return `true`. +/// Returns `true` if fully drained, `false` on timeout. /// /// # Safety /// @@ -402,10 +440,7 @@ pub unsafe extern "C" fn lj_logger_flush(logger: *mut lj_logger, timeout_ms: u64 Some(logger) => logger, None => return false, }; - match &logger.inner.backend { - Backend::Grpc(client) => flush_grpc(client, Duration::from_millis(timeout_ms)), - Backend::Http(_) => true, - } + flush_logger(&logger.inner, Duration::from_millis(timeout_ms)) } /// Returns the number of async sends that failed on the network. @@ -416,10 +451,7 @@ pub unsafe extern "C" fn lj_logger_flush(logger: *mut lj_logger, timeout_ms: u64 #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_async_errors(logger: *mut lj_logger) -> u64 { match unsafe { logger.as_ref() } { - Some(logger) => match &logger.inner.backend { - Backend::Grpc(client) => client.shared.async_errors.load(Ordering::Relaxed), - Backend::Http(_) => 0, - }, + Some(logger) => logger_engine(&logger.inner).errors.load(Ordering::Relaxed), None => 0, } } @@ -432,10 +464,7 @@ pub unsafe extern "C" fn lj_logger_async_errors(logger: *mut lj_logger) -> u64 { #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_async_dropped(logger: *mut lj_logger) -> u64 { match unsafe { logger.as_ref() } { - Some(logger) => match &logger.inner.backend { - Backend::Grpc(client) => client.shared.async_dropped.load(Ordering::Relaxed), - Backend::Http(_) => 0, - }, + Some(logger) => logger_engine(&logger.inner).dropped.load(Ordering::Relaxed), None => 0, } } @@ -448,10 +477,7 @@ pub unsafe extern "C" fn lj_logger_async_dropped(logger: *mut lj_logger) -> u64 #[unsafe(no_mangle)] pub unsafe extern "C" fn lj_logger_async_inflight(logger: *mut lj_logger) -> u64 { match unsafe { logger.as_ref() } { - Some(logger) => match &logger.inner.backend { - Backend::Grpc(client) => client.shared.inflight.load(Ordering::SeqCst), - Backend::Http(_) => 0, - }, + Some(logger) => logger_engine(&logger.inner).inflight.load(Ordering::SeqCst), None => 0, } } @@ -468,9 +494,7 @@ pub unsafe extern "C" fn lj_logger_free(logger: *mut lj_logger) { return; } let boxed = unsafe { Box::from_raw(logger) }; - if let Backend::Grpc(client) = &boxed.inner.backend { - let _ = flush_grpc(client, boxed.inner.timeout); - } + let _ = flush_logger(&boxed.inner, boxed.inner.timeout); } enum BackendKind { @@ -494,27 +518,19 @@ unsafe fn new_logger_impl(endpoint: *const c_char, service_name: *const c_char, let service_name = read_required(service_name, "service_name")?; let timeout = Duration::from_millis(timeout_ms.max(1)); let backend = match kind { - BackendKind::Http => Backend::Http(parse_http_endpoint(&endpoint)?), + BackendKind::Http => { + let pool = Arc::new(HttpPool { endpoint: parse_http_endpoint(&endpoint)?, idle: Mutex::new(Vec::new()) }); + Backend::Http(HttpClient { runtime: OnceLock::new(), engine: AsyncEngine::new(), pool }) + } BackendKind::Grpc => { - let shared = Arc::new(GrpcShared { - endpoint: normalise_grpc_endpoint(&endpoint), - channel: TokioMutex::new(None), - backpressure: Mutex::new(Backpressure { - model: LJ_BACKPRESSURE_DROP, - semaphore: Arc::new(Semaphore::new(DEFAULT_BACKPRESSURE_CAPACITY)), - }), - inflight: AtomicU64::new(0), - async_errors: AtomicU64::new(0), - async_dropped: AtomicU64::new(0), - idle: Notify::new(), - }); - Backend::Grpc(GrpcClient { runtime: grpc_runtime()?, shared }) + let channel = Arc::new(GrpcChannel { endpoint: normalise_grpc_endpoint(&endpoint), channel: TokioMutex::new(None) }); + Backend::Grpc(GrpcClient { runtime: make_runtime()?, engine: AsyncEngine::new(), channel }) } }; Ok(Logger { backend, service_name, timeout }) } -fn grpc_runtime() -> Result { +fn make_runtime() -> Result { Builder::new_multi_thread().enable_all().build().map_err(|err| err.to_string()) } @@ -692,72 +708,102 @@ fn key_value(key: impl Into, value: AnyValue) -> KeyValue { fn send_request(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { match &logger.backend { - Backend::Http(endpoint) => post_otlp_http(endpoint, logger.timeout, &request).map_err(|err| err.to_string()), + Backend::Http(client) => post_otlp_http_once(&client.pool.endpoint, logger.timeout, &request).map_err(|err| err.to_string()), Backend::Grpc(client) => { - client.runtime.block_on(send_otlp_grpc(client.shared.endpoint.clone(), logger.timeout, request)).map_err(|err| err.to_string()) + client.runtime.block_on(send_otlp_grpc(client.channel.endpoint.clone(), logger.timeout, request)).map_err(|err| err.to_string()) } } } fn send_request_reuse(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { match &logger.backend { - Backend::Http(endpoint) => post_otlp_http(endpoint, logger.timeout, &request).map_err(|err| err.to_string()), - Backend::Grpc(client) => client.runtime.block_on(send_pooled_async(client.shared.clone(), logger.timeout, request)), + Backend::Http(client) => { + let payload = request.encode_to_vec(); + http_send_blocking(&client.pool, logger.timeout, &payload).map_err(|err| err.to_string()) + } + Backend::Grpc(client) => client.runtime.block_on(send_pooled_async(client.channel.clone(), logger.timeout, request)), } } fn send_request_async(logger: &Logger, request: ExportLogsServiceRequest) -> Result<(), String> { match &logger.backend { - Backend::Http(_) => Err("async send is not supported for HTTP loggers yet".to_string()), - Backend::Grpc(client) => enqueue_async_grpc(client, logger.timeout, request), + Backend::Grpc(client) => { + let channel = client.channel.clone(); + let timeout = logger.timeout; + enqueue_async(&client.runtime, &client.engine, move || send_pooled_async(channel, timeout, request)) + } + Backend::Http(client) => { + let runtime = http_runtime(client)?; + let pool = client.pool.clone(); + let timeout = logger.timeout; + let payload = request.encode_to_vec(); + enqueue_async(runtime, &client.engine, move || http_send_async(pool, timeout, payload)) + } + } +} + +fn http_runtime(client: &HttpClient) -> Result<&Runtime, String> { + if let Some(runtime) = client.runtime.get() { + return Ok(runtime); } + let runtime = make_runtime()?; + let _ = client.runtime.set(runtime); + Ok(client.runtime.get().expect("http runtime set")) } -fn enqueue_async_grpc(client: &GrpcClient, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { +fn enqueue_async(runtime: &Runtime, engine: &Arc, make_fut: F) -> Result<(), String> +where + F: FnOnce() -> Fut + Send + 'static, + Fut: std::future::Future> + Send + 'static, +{ let (model, semaphore) = { - let cfg = client.shared.backpressure.lock().map_err(|_| "backpressure lock poisoned".to_string())?; + let cfg = engine.backpressure.lock().map_err(|_| "backpressure lock poisoned".to_string())?; (cfg.model, cfg.semaphore.clone()) }; match model { - LJ_BACKPRESSURE_UNBOUNDED => spawn_send(client, timeout, request, None), + LJ_BACKPRESSURE_UNBOUNDED => spawn_task(runtime, engine, make_fut, None), LJ_BACKPRESSURE_DROP => match semaphore.try_acquire_owned() { - Ok(permit) => spawn_send(client, timeout, request, Some(permit)), + Ok(permit) => spawn_task(runtime, engine, make_fut, Some(permit)), Err(_) => { - client.shared.async_dropped.fetch_add(1, Ordering::Relaxed); + engine.dropped.fetch_add(1, Ordering::Relaxed); } }, LJ_BACKPRESSURE_BLOCK => { - let permit = client.runtime.block_on(semaphore.acquire_owned()).map_err(|err| err.to_string())?; - spawn_send(client, timeout, request, Some(permit)); + let permit = runtime.block_on(semaphore.acquire_owned()).map_err(|err| err.to_string())?; + spawn_task(runtime, engine, make_fut, Some(permit)); } other => return Err(format!("invalid backpressure model {other}")), } Ok(()) } -fn spawn_send(client: &GrpcClient, timeout: Duration, request: ExportLogsServiceRequest, permit: Option) { - let shared = client.shared.clone(); - shared.inflight.fetch_add(1, Ordering::SeqCst); - client.runtime.spawn(async move { +fn spawn_task(runtime: &Runtime, engine: &Arc, make_fut: F, permit: Option) +where + F: FnOnce() -> Fut + Send + 'static, + Fut: std::future::Future> + Send + 'static, +{ + let engine = engine.clone(); + engine.inflight.fetch_add(1, Ordering::SeqCst); + runtime.spawn(async move { let _permit = permit; - if send_pooled_async(shared.clone(), timeout, request).await.is_err() { - shared.async_errors.fetch_add(1, Ordering::Relaxed); + if make_fut().await.is_err() { + engine.errors.fetch_add(1, Ordering::Relaxed); } - if shared.inflight.fetch_sub(1, Ordering::SeqCst) == 1 { - shared.idle.notify_waiters(); + if engine.inflight.fetch_sub(1, Ordering::SeqCst) == 1 { + engine.idle.notify_waiters(); } }); } -fn flush_grpc(client: &GrpcClient, timeout: Duration) -> bool { - client.runtime.block_on(async { +fn flush_engine(runtime: &Runtime, engine: &Arc, timeout: Duration) -> bool { + runtime.block_on(async { let deadline = tokio::time::Instant::now() + timeout; loop { - if client.shared.inflight.load(Ordering::SeqCst) == 0 { + if engine.inflight.load(Ordering::SeqCst) == 0 { return true; } - let notified = client.shared.idle.notified(); - if client.shared.inflight.load(Ordering::SeqCst) == 0 { + let notified = engine.idle.notified(); + if engine.inflight.load(Ordering::SeqCst) == 0 { return true; } let now = tokio::time::Instant::now(); @@ -765,31 +811,31 @@ fn flush_grpc(client: &GrpcClient, timeout: Duration) -> bool { return false; } if tokio::time::timeout(deadline - now, notified).await.is_err() { - return client.shared.inflight.load(Ordering::SeqCst) == 0; + return engine.inflight.load(Ordering::SeqCst) == 0; } } }) } -async fn send_pooled_async(shared: Arc, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { +async fn send_pooled_async(channel: Arc, timeout: Duration, request: ExportLogsServiceRequest) -> Result<(), String> { // Connect-once: hold the lock across connect so a concurrent burst opens a // single connection; release it before export so sends run concurrently over // the shared multiplexed channel. - let channel = { - let mut guard = shared.channel.lock().await; + let active = { + let mut guard = channel.channel.lock().await; match guard.as_ref() { - Some(channel) => channel.clone(), + Some(active) => active.clone(), None => { - let channel = connect_channel(&shared.endpoint, timeout).await.map_err(|err| err.to_string())?; - *guard = Some(channel.clone()); - channel + let active = connect_channel(&channel.endpoint, timeout).await.map_err(|err| err.to_string())?; + *guard = Some(active.clone()); + active } } }; - let result = export_on_channel(channel, request).await.map_err(|err| err.to_string()); + let result = export_on_channel(active, request).await.map_err(|err| err.to_string()); if result.is_err() { - *shared.channel.lock().await = None; + *channel.channel.lock().await = None; } result } @@ -811,22 +857,23 @@ async fn send_otlp_grpc(endpoint: String, timeout: Duration, request: ExportLogs Ok(()) } -fn post_otlp_http(endpoint: &HttpEndpoint, timeout: Duration, request: &ExportLogsServiceRequest) -> std::io::Result<()> { +/// Fresh-connect, `Connection: close` POST. Baseline used by `lj_logger_log`. +fn post_otlp_http_once(endpoint: &HttpEndpoint, timeout: Duration, request: &ExportLogsServiceRequest) -> std::io::Result<()> { let payload = request.encode_to_vec(); let mut stream = TcpStream::connect(endpoint.authority.as_str())?; stream.set_read_timeout(Some(timeout))?; stream.set_write_timeout(Some(timeout))?; - stream.write_all( - format!( - "POST {} HTTP/1.1\r\nHost: {}\r\nContent-Type: application/x-protobuf\r\nContent-Length: {}\r\nConnection: close\r\n\r\n", - endpoint.path, - endpoint.host_header, - payload.len() - ) - .as_bytes(), - )?; - stream.write_all(&payload)?; - stream.shutdown(Shutdown::Write)?; + stream.set_nodelay(true)?; + let header = format!( + "POST {} HTTP/1.1\r\nHost: {}\r\nContent-Type: application/x-protobuf\r\nContent-Length: {}\r\nConnection: close\r\n\r\n", + endpoint.path, + endpoint.host_header, + payload.len() + ); + let mut framed = Vec::with_capacity(header.len() + payload.len()); + framed.extend_from_slice(header.as_bytes()); + framed.extend_from_slice(&payload); + stream.write_all(&framed)?; let mut response = Vec::new(); stream.read_to_end(&mut response)?; @@ -839,6 +886,115 @@ fn post_otlp_http(endpoint: &HttpEndpoint, timeout: Duration, request: &ExportLo Err(std::io::Error::other(format!("HTTP export failed: {status}"))) } +async fn http_send_async(pool: Arc, timeout: Duration, payload: Vec) -> Result<(), String> { + tokio::task::spawn_blocking(move || http_send_blocking(&pool, timeout, &payload)) + .await + .map_err(|err| err.to_string())? + .map_err(|err| err.to_string()) +} + +/// Keep-alive POST over a pooled connection, with one fresh-connect retry. +fn http_send_blocking(pool: &HttpPool, timeout: Duration, payload: &[u8]) -> std::io::Result<()> { + if let Some(stream) = pool_checkout(pool) + && http_exchange(pool, stream, payload).is_ok() + { + return Ok(()); + } + let stream = http_connect(pool, timeout)?; + http_exchange(pool, stream, payload) +} + +fn pool_checkout(pool: &HttpPool) -> Option { + pool.idle.lock().ok().and_then(|mut idle| idle.pop()) +} + +fn pool_checkin(pool: &HttpPool, stream: TcpStream) { + if let Ok(mut idle) = pool.idle.lock() + && idle.len() < MAX_HTTP_POOL + { + idle.push(stream); + } +} + +fn http_connect(pool: &HttpPool, timeout: Duration) -> std::io::Result { + let stream = TcpStream::connect(pool.endpoint.authority.as_str())?; + stream.set_read_timeout(Some(timeout))?; + stream.set_write_timeout(Some(timeout))?; + stream.set_nodelay(true)?; + Ok(stream) +} + +fn http_exchange(pool: &HttpPool, mut stream: TcpStream, payload: &[u8]) -> std::io::Result<()> { + let header = format!( + "POST {} HTTP/1.1\r\nHost: {}\r\nContent-Type: application/x-protobuf\r\nContent-Length: {}\r\n\r\n", + pool.endpoint.path, + pool.endpoint.host_header, + payload.len() + ); + // Single write (header + body) so Nagle/delayed-ACK does not stall the request. + let mut framed = Vec::with_capacity(header.len() + payload.len()); + framed.extend_from_slice(header.as_bytes()); + framed.extend_from_slice(payload); + stream.write_all(&framed)?; + stream.flush()?; + + let (status_ok, keep_alive) = read_http_response(&mut stream)?; + if !status_ok { + return Err(std::io::Error::other("HTTP export failed")); + } + if keep_alive { + pool_checkin(pool, stream); + } + Ok(()) +} + +/// Reads one HTTP/1.1 response. Returns `(status_ok, can_keep_alive)`. +fn read_http_response(stream: &mut TcpStream) -> std::io::Result<(bool, bool)> { + let mut reader = std::io::BufReader::new(stream); + + let mut head = String::new(); + loop { + let mut line = String::new(); + let read = reader.read_line(&mut line)?; + if read == 0 || line == "\r\n" || line == "\n" { + break; + } + head.push_str(&line); + } + + let status_line = head.lines().next().unwrap_or_default(); + let status_ok = status_line.contains(" 200 ") || status_line.contains(" 202 ") || status_line.contains(" 204 "); + + let mut content_length: Option = None; + let mut conn_close = false; + for line in head.lines().skip(1) { + if let Some((key, value)) = line.split_once(':') { + let key = key.trim().to_ascii_lowercase(); + let value = value.trim(); + if key == "content-length" { + content_length = value.parse::().ok(); + } else if key == "connection" && value.eq_ignore_ascii_case("close") { + conn_close = true; + } + } + } + + let keep_alive = match content_length { + Some(len) => { + let mut body = vec![0u8; len]; + reader.read_exact(&mut body)?; + !conn_close + } + None => { + let mut sink = Vec::new(); + let _ = reader.read_to_end(&mut sink); + false + } + }; + + Ok((status_ok, keep_alive)) +} + fn parse_http_endpoint(raw: &str) -> Result { let raw = raw.trim(); if let Some(rest) = raw.strip_prefix("https://") { From dc91e0e2142735892717303c20a8074c564a01e2 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:07:16 +0200 Subject: [PATCH 16/21] Add unit tests --- liblogjet/tests/unit/batch_ut.rs | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/liblogjet/tests/unit/batch_ut.rs b/liblogjet/tests/unit/batch_ut.rs index b7b2632..390a3e1 100644 --- a/liblogjet/tests/unit/batch_ut.rs +++ b/liblogjet/tests/unit/batch_ut.rs @@ -1,18 +1,19 @@ use std::ffi::{CStr, CString}; use std::ptr; +use std::sync::{Mutex, OnceLock}; use std::time::Duration; use opentelemetry_proto::tonic::common::v1::any_value::Value; -use super::{Backend, HttpEndpoint, LjLogRecord, Logger, build_batch_request}; +use super::{AsyncEngine, Backend, HttpClient, HttpEndpoint, HttpPool, LjLogRecord, Logger, build_batch_request}; fn test_logger(service: &str) -> Logger { + let pool = std::sync::Arc::new(HttpPool { + endpoint: HttpEndpoint { authority: "127.0.0.1:4318".to_string(), host_header: "127.0.0.1:4318".to_string(), path: "/v1/logs".to_string() }, + idle: Mutex::new(Vec::new()), + }); Logger { - backend: Backend::Http(HttpEndpoint { - authority: "127.0.0.1:4318".to_string(), - host_header: "127.0.0.1:4318".to_string(), - path: "/v1/logs".to_string(), - }), + backend: Backend::Http(HttpClient { runtime: OnceLock::new(), engine: AsyncEngine::new(), pool }), service_name: service.to_string(), timeout: Duration::from_millis(1000), } From ab8a9f337f7f895fc8fda29dfd59150a34775e10 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Tue, 23 Jun 2026 17:08:15 +0200 Subject: [PATCH 17/21] Autoformat --- demo/benchmark-clib/main.rs | 25 ++++++++++++------------- liblogjet/src/lib.rs | 5 ++++- 2 files changed, 16 insertions(+), 14 deletions(-) diff --git a/demo/benchmark-clib/main.rs b/demo/benchmark-clib/main.rs index bd37519..46890be 100644 --- a/demo/benchmark-clib/main.rs +++ b/demo/benchmark-clib/main.rs @@ -20,8 +20,8 @@ use std::ptr; use std::time::{Instant, SystemTime, UNIX_EPOCH}; use liblogjet::{ - LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, lj_logger_log, lj_logger_log_async, - lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, lj_logger_new_http, lj_logger_set_backpressure, + LjAttribute, LjLogRecord, lj_error_message, lj_logger, lj_logger_async_dropped, lj_logger_async_errors, lj_logger_flush, lj_logger_free, + lj_logger_log, lj_logger_log_async, lj_logger_log_batch, lj_logger_log_reuse, lj_logger_new_grpc, lj_logger_new_http, lj_logger_set_backpressure, }; use logjet::{LogjetWriter, RecordType}; @@ -125,14 +125,7 @@ fn print_legend() { #[allow(clippy::too_many_arguments)] fn run_and_print_transport( - proto: &str, - new_fn: NewFn, - endpoint: &CStr, - endpoint_str: &str, - service: &CStr, - record: &mut LjLogRecord, - count: usize, - batch_size: usize, + proto: &str, new_fn: NewFn, endpoint: &CStr, endpoint_str: &str, service: &CStr, record: &mut LjLogRecord, count: usize, batch_size: usize, file_stats: Option<&Stats>, ) { let per_connection = match unsafe { run_backend_phase(endpoint, service, record, count, new_fn, lj_logger_log) } { @@ -236,7 +229,9 @@ struct BackendResult { cold_first: f64, } -unsafe fn run_backend_phase(endpoint: &CStr, service: &CStr, record: &mut LjLogRecord, count: usize, new_fn: NewFn, log_fn: LogFn) -> Result { +unsafe fn run_backend_phase( + endpoint: &CStr, service: &CStr, record: &mut LjLogRecord, count: usize, new_fn: NewFn, log_fn: LogFn, +) -> Result { let logger = unsafe { new_fn(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; if logger.is_null() { return Err(last_error()); @@ -289,7 +284,9 @@ fn clone_record(template: &LjLogRecord) -> LjLogRecord { } } -unsafe fn run_batch_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, batch_size: usize, new_fn: NewFn) -> Result { +unsafe fn run_batch_phase( + endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, batch_size: usize, new_fn: NewFn, +) -> Result { let logger = unsafe { new_fn(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; if logger.is_null() { return Err(last_error()); @@ -341,7 +338,9 @@ struct AsyncResult { dropped: u64, } -unsafe fn run_async_phase(endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, new_fn: NewFn, backpressure: Option<(i32, usize)>) -> Result { +unsafe fn run_async_phase( + endpoint: &CStr, service: &CStr, template: &LjLogRecord, count: usize, new_fn: NewFn, backpressure: Option<(i32, usize)>, +) -> Result { let logger = unsafe { new_fn(endpoint.as_ptr(), service.as_ptr(), TIMEOUT_MS) }; if logger.is_null() { return Err(last_error()); diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index bd3f63d..bfae8b1 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -136,7 +136,10 @@ struct AsyncEngine { impl AsyncEngine { fn new() -> Arc { Arc::new(Self { - backpressure: Mutex::new(Backpressure { model: LJ_BACKPRESSURE_DROP, semaphore: Arc::new(Semaphore::new(DEFAULT_BACKPRESSURE_CAPACITY)) }), + backpressure: Mutex::new(Backpressure { + model: LJ_BACKPRESSURE_DROP, + semaphore: Arc::new(Semaphore::new(DEFAULT_BACKPRESSURE_CAPACITY)), + }), inflight: AtomicU64::new(0), errors: AtomicU64::new(0), dropped: AtomicU64::new(0), From 1a7027e65cca4b303b03f7b4bd836d2f85fbf2a1 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Thu, 23 Jul 2026 15:21:41 +0200 Subject: [PATCH 18/21] Update docs --- doc/c-cpp-integration.md | 135 ++++++++++++++++++++++++++++++++++----- 1 file changed, 120 insertions(+), 15 deletions(-) diff --git a/doc/c-cpp-integration.md b/doc/c-cpp-integration.md index 6beba8a..8c7e7d1 100644 --- a/doc/c-cpp-integration.md +++ b/doc/c-cpp-integration.md @@ -98,20 +98,125 @@ int main() { ## Performance: connection reuse, batching, async -`lj_logger_log` opens a fresh connection per record (simplest, most robust). For -high-rate logging, additive entry points reuse the connection and amortise the -network cost, for both gRPC and HTTP (HTTP via a keep-alive connection pool): - -- `lj_logger_log_reuse(logger, record)` — one record over a persistent connection. -- `lj_logger_log_batch(logger, records, len)` — many records in one request. -- `lj_logger_log_async(logger, record)` / `lj_logger_log_batch_async(...)` — - non-blocking; hands the send to a background runtime and returns immediately. - -Async sends are bounded by a backpressure policy -(`lj_logger_set_backpressure(logger, model, capacity)`; models -`LJ_BACKPRESSURE_UNBOUNDED` / `LJ_BACKPRESSURE_DROP` / `LJ_BACKPRESSURE_BLOCK`, -default `DROP`/1024). Drain in-flight sends with -`lj_logger_flush(logger, timeout_ms)` (also done on `lj_logger_free`), and observe -`lj_logger_async_errors` / `lj_logger_async_dropped` / `lj_logger_async_inflight`. +`lj_logger_log` opens a fresh connection per record — simplest and most robust, +but the per-connection handshake dominates at scale. Four additional send paths +eliminate that overhead for both gRPC and HTTP (HTTP uses a keep-alive connection +pool, gRPC caches a multiplexed channel): + +| Function | What it does | When to use | +|---|---|---| +| `lj_logger_log` | Fresh connection per record | Low rate, simplest path | +| `lj_logger_log_reuse` | One record over a persistent connection | Moderate rate, replaces `_log` for a speedup | +| `lj_logger_log_batch` | Many records in one request (amortised) | Bulk export, flush loops | +| `lj_logger_log_async` | Non-blocking, hands send to a background runtime | High rate, caller must not block | +| `lj_logger_log_batch_async` | Non-blocking batch send | Bulk export without caller latency | + +All `_reuse`, `_batch`, and `_async` paths share the persistent connection — the +first call establishes it (slightly slower), every subsequent call reuses it. + +### Error semantics + +| Path | Return value `false` means | Network failures | +|---|---|---| +| `lj_logger_log`, `_reuse`, `_batch` | Validation, connection, or HTTP/gRPC error | Returned synchronously via `lj_error_message()` | +| `lj_logger_log_async`, `_batch_async` | Validation error only | Counted later via `lj_logger_async_errors()` | + +The async paths never report network failures in-band because the send happens +after the function returns. Check `lj_logger_async_errors` after `lj_logger_flush` +or `lj_logger_free`. + +### Thread safety + +A single `lj_logger *` may be shared across threads: the underlying gRPC channel +and HTTP connection pool are internally synchronised. The async engine (counters, +backpressure semaphore) is also thread-safe. + +### Async backpressure + +`lj_logger_log_async` and `lj_logger_log_batch_async` never block the caller. +Outstanding sends are bounded by a backpressure policy set before the first send: + +```c +lj_logger_set_backpressure(logger, LJ_BACKPRESSURE_DROP, 1024); // default +``` + +| Model | Behaviour | +|---|---| +| `LJ_BACKPRESSURE_UNBOUNDED` | Spawn every send (risk: memory under load) | +| `LJ_BACKPRESSURE_DROP` | Bounded to `capacity`; drop + count when full | +| `LJ_BACKPRESSURE_BLOCK` | Bounded; block the caller until a slot frees | + +Drain and observe: + +```c +// Block until all in-flight sends finish or 5000 ms elapses +bool drained = lj_logger_flush(logger, 5000); + +uint64_t errors = lj_logger_async_errors(logger); +uint64_t dropped = lj_logger_async_dropped(logger); +uint64_t inflight = lj_logger_async_inflight(logger); +``` + +`lj_logger_free` also drains in-flight sends before freeing resources. + +### Async example (gRPC) + +```cpp +#include "liblogjet.h" +#include +#include + +int main() { + void *so = dlopen("./liblogjet.so", RTLD_NOW | RTLD_LOCAL); + + auto new_grpc = (lj_logger *(*)(const char *, const char *, uint64_t)) + dlsym(so, "lj_logger_new_grpc"); + auto log_async = (bool (*)(lj_logger *, const lj_log_record *)) + dlsym(so, "lj_logger_log_async"); + auto set_bp = (bool (*)(lj_logger *, int32_t, size_t)) + dlsym(so, "lj_logger_set_backpressure"); + auto flush = (bool (*)(lj_logger *, uint64_t)) + dlsym(so, "lj_logger_flush"); + auto async_errors = (uint64_t (*)(lj_logger *)) + dlsym(so, "lj_logger_async_errors"); + auto async_dropped = (uint64_t (*)(lj_logger *)) + dlsym(so, "lj_logger_async_dropped"); + auto free_logger = (void (*)(lj_logger *)) + dlsym(so, "lj_logger_free"); + + lj_logger *logger = new_grpc("127.0.0.1:4317", "demo-async", 2000); + set_bp(logger, LJ_BACKPRESSURE_DROP, 256); + + lj_attribute attrs[] = {{"tag", "async-demo"}}; + lj_log_record record{ + 0, // timestamp (0 = now) + LJ_SEVERITY_INFO, // severity + "INFO", // severity text + "async hello", // body + attrs, // attributes + 1, // attributes count + }; + + for (int i = 0; i < 1000; i++) { + log_async(logger, &record); + } + + flush(logger, 5000); + + uint64_t errors = async_errors(logger); + uint64_t dropped = async_dropped(logger); + printf("errors=%lu dropped=%lu\n", errors, dropped); + + free_logger(logger); + return 0; +} +``` + +### Migration + +Replace `lj_logger_log` with `lj_logger_log_reuse` for an immediate speedup with +no change to call semantics. For bulk inserts, switch to `lj_logger_log_batch`. +When caller latency matters, use `lj_logger_log_async` or +`lj_logger_log_batch_async` with backpressure control. A measured comparison lives in [`demo/benchmark-clib`](../demo/benchmark-clib). From 20ba89ed1d7bf61b90fc8683126e756f39c26cd0 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Thu, 23 Jul 2026 15:21:55 +0200 Subject: [PATCH 19/21] Add docstrings --- liblogjet/include/liblogjet.h | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+) diff --git a/liblogjet/include/liblogjet.h b/liblogjet/include/liblogjet.h index 76a311f..cd2ca82 100644 --- a/liblogjet/include/liblogjet.h +++ b/liblogjet/include/liblogjet.h @@ -160,16 +160,35 @@ const char *lj_version(void); const char *lj_error_message(void); lj_logger *lj_logger_new_http(const char *endpoint, const char *service_name, uint64_t timeout_ms); lj_logger *lj_logger_new_grpc(const char *endpoint, const char *service_name, uint64_t timeout_ms); +// Send one log record. Opens a fresh connection — simplest, most robust. bool lj_logger_log(lj_logger *logger, const lj_log_record *record); +// Send one record over a persistent gRPC channel or HTTP keep-alive connection. +// First call establishes the connection (slightly slower); subsequent calls reuse it. bool lj_logger_log_reuse(lj_logger *logger, const lj_log_record *record); +// Send many records in one export request over a persistent connection. +// Records are grouped by service name, resource attributes, and scope. +// A len of 0 or null records is a successful no-op. bool lj_logger_log_batch(lj_logger *logger, const lj_log_record *records, size_t len); +// Enqueue one record for send on a background runtime; returns immediately. +// Returns false only on validation errors. Network failures are counted via +// lj_logger_async_errors(); records dropped by backpressure via lj_logger_async_dropped(). bool lj_logger_log_async(lj_logger *logger, const lj_log_record *record); +// Enqueue a batch for background send. Same error semantics as lj_logger_log_async. bool lj_logger_log_batch_async(lj_logger *logger, const lj_log_record *records, size_t len); +// Configure async backpressure. model is LJ_BACKPRESSURE_UNBOUNDED / _DROP / _BLOCK. +// capacity is the max in-flight sends for bounded models (ignored for unbounded). +// Default: LJ_BACKPRESSURE_DROP, capacity 1024. Call before first async send. bool lj_logger_set_backpressure(lj_logger *logger, int32_t model, size_t capacity); +// Block until all in-flight async sends complete or timeout_ms elapses. +// Returns true if fully drained. Also called by lj_logger_free. bool lj_logger_flush(lj_logger *logger, uint64_t timeout_ms); +// Count of async sends that failed on the network. uint64_t lj_logger_async_errors(lj_logger *logger); +// Count of records dropped by bounded backpressure (LJ_BACKPRESSURE_DROP). uint64_t lj_logger_async_dropped(lj_logger *logger); +// Number of async sends currently in flight. uint64_t lj_logger_async_inflight(lj_logger *logger); +// Free the logger. Drains in-flight async sends first. Accepts NULL. void lj_logger_free(lj_logger *logger); lj_ingest_plugin *lj_ingest_create(void); From 5b167c6da5f0273eb8c4bf8d9920e87d83cc0222 Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Thu, 23 Jul 2026 15:23:26 +0200 Subject: [PATCH 20/21] Add unit tests for C ABI --- liblogjet/src/lib.rs | 4 + liblogjet/tests/unit/async_ut.rs | 341 ++++++++++++++++++++++++ liblogjet/tests/unit/batch_ut.rs | 428 ++++++++++++++++++++++++++++++- 3 files changed, 772 insertions(+), 1 deletion(-) create mode 100644 liblogjet/tests/unit/async_ut.rs diff --git a/liblogjet/src/lib.rs b/liblogjet/src/lib.rs index bfae8b1..dce2bde 100644 --- a/liblogjet/src/lib.rs +++ b/liblogjet/src/lib.rs @@ -1068,3 +1068,7 @@ fn set_last_error(message: impl Into) { #[cfg(test)] #[path = "../tests/unit/batch_ut.rs"] mod batch_ut; + +#[cfg(test)] +#[path = "../tests/unit/async_ut.rs"] +mod async_ut; diff --git a/liblogjet/tests/unit/async_ut.rs b/liblogjet/tests/unit/async_ut.rs new file mode 100644 index 0000000..5cb246a --- /dev/null +++ b/liblogjet/tests/unit/async_ut.rs @@ -0,0 +1,341 @@ +use std::ptr; +use std::sync::atomic::Ordering; +use std::sync::Arc; +use std::time::Duration; + +use tokio::runtime::Builder; +use tokio::sync::{Semaphore, oneshot}; + +use super::{ + Backend, HttpClient, HttpEndpoint, HttpPool, Logger, lj_logger, LjLogRecord, + LJ_BACKPRESSURE_BLOCK, LJ_BACKPRESSURE_DROP, LJ_BACKPRESSURE_UNBOUNDED, DEFAULT_BACKPRESSURE_CAPACITY, + AsyncEngine, enqueue_async, flush_engine, + lj_logger_flush, lj_logger_free, + lj_logger_async_errors, lj_logger_async_dropped, lj_logger_async_inflight, + lj_logger_log_async, lj_logger_set_backpressure, +}; + +fn test_runtime() -> tokio::runtime::Runtime { + Builder::new_multi_thread().enable_time().build().unwrap() +} + +fn test_logger() -> Logger { + let pool = Arc::new(HttpPool { + endpoint: HttpEndpoint { authority: "127.0.0.1:4318".to_string(), host_header: "127.0.0.1:4318".to_string(), path: "/v1/logs".to_string() }, + idle: std::sync::Mutex::new(Vec::new()), + }); + Logger { + backend: Backend::Http(HttpClient { runtime: std::sync::OnceLock::new(), engine: AsyncEngine::new(), pool }), + service_name: "svc".to_string(), + timeout: Duration::from_millis(1000), + } +} + +fn test_logger_ptr() -> *mut lj_logger { + Box::into_raw(Box::new(lj_logger { inner: test_logger() })) +} + +fn set_engine_capacity(engine: &AsyncEngine, model: i32, capacity: usize) { + let mut bp = engine.backpressure.lock().unwrap(); + bp.model = model; + bp.semaphore = Arc::new(Semaphore::new(capacity)); +} + +// +// AsyncEngine defaults +// + +#[test] +fn engine_defaults_to_drop_model() { + let engine = AsyncEngine::new(); + let bp = engine.backpressure.lock().unwrap(); + assert_eq!(bp.model, LJ_BACKPRESSURE_DROP); +} + +#[test] +fn engine_default_capacity_is_1024() { + let engine = AsyncEngine::new(); + let bp = engine.backpressure.lock().unwrap(); + assert_eq!(bp.semaphore.available_permits(), DEFAULT_BACKPRESSURE_CAPACITY); +} + +#[test] +fn engine_counters_start_at_zero() { + let engine = AsyncEngine::new(); + assert_eq!(engine.errors.load(Ordering::Relaxed), 0); + assert_eq!(engine.dropped.load(Ordering::Relaxed), 0); + assert_eq!(engine.inflight.load(Ordering::SeqCst), 0); +} + +// +// enqueue_async: inflight / errors +// + +#[test] +fn enqueue_increments_inflight() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + let (tx, rx) = oneshot::channel::<()>(); + + enqueue_async(&runtime, &engine, move || async move { + let _ = rx.await; + Ok(()) + }).unwrap(); + + assert_eq!(engine.inflight.load(Ordering::SeqCst), 1); + tx.send(()).unwrap(); +} + +#[test] +fn enqueue_decrements_inflight_on_completion() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + + enqueue_async(&runtime, &engine, || async { Ok(()) }).unwrap(); + std::thread::sleep(Duration::from_millis(100)); + + assert_eq!(engine.inflight.load(Ordering::SeqCst), 0); +} + +#[test] +fn enqueue_counts_task_errors() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + + enqueue_async(&runtime, &engine, || async { Err("fail".to_string()) }).unwrap(); + std::thread::sleep(Duration::from_millis(100)); + + assert_eq!(engine.errors.load(Ordering::Relaxed), 1); + assert_eq!(engine.inflight.load(Ordering::SeqCst), 0); +} + +// +// Backpressure: DROP +// + +#[test] +fn drop_drops_when_semaphore_exhausted() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + set_engine_capacity(&engine, LJ_BACKPRESSURE_DROP, 1); + + let (tx, rx) = oneshot::channel::<()>(); + + enqueue_async(&runtime, &engine, move || async move { + let _ = rx.await; + Ok(()) + }).unwrap(); + assert_eq!(engine.inflight.load(Ordering::SeqCst), 1); + + let result = enqueue_async(&runtime, &engine, || async { Ok(()) }); + assert!(result.is_ok()); + assert_eq!(engine.dropped.load(Ordering::Relaxed), 1); + + tx.send(()).unwrap(); +} + +#[test] +fn drop_returns_ok_even_when_record_is_dropped() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + set_engine_capacity(&engine, LJ_BACKPRESSURE_DROP, 0); + + let result = enqueue_async(&runtime, &engine, || async { Ok(()) }); + assert!(result.is_ok()); + assert_eq!(engine.dropped.load(Ordering::Relaxed), 1); +} + +// +// Backpressure: BLOCK +// + +#[test] +fn block_waits_for_permit_release() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + set_engine_capacity(&engine, LJ_BACKPRESSURE_BLOCK, 1); + + let (tx, rx) = oneshot::channel::<()>(); + let (ready_tx, ready_rx) = oneshot::channel::<()>(); + + // First enqueue holds the only permit. + enqueue_async(&runtime, &engine, move || async move { + let _ = rx.await; + Ok(()) + }).unwrap(); + + // Second enqueue should block until the permit is released. + let engine2 = engine.clone(); + let handle = std::thread::spawn(move || { + let rt = Builder::new_current_thread().enable_time().build().unwrap(); + let _ = ready_tx.send(()); + enqueue_async(&rt, &engine2, || async { Ok(()) }) + }); + + // Wait until the thread is ready (blocked on semaphore). + ready_rx.blocking_recv().unwrap(); + std::thread::sleep(Duration::from_millis(30)); + + // Release the first task; the blocked thread should now succeed. + tx.send(()).unwrap(); + let result = handle.join().unwrap(); + assert!(result.is_ok()); +} + +// +// Backpressure: UNBOUNDED +// + +#[test] +fn unbounded_ignores_capacity_limit() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + set_engine_capacity(&engine, LJ_BACKPRESSURE_UNBOUNDED, 1); + + let (tx1, rx1) = oneshot::channel::<()>(); + let (tx2, rx2) = oneshot::channel::<()>(); + + enqueue_async(&runtime, &engine, move || async move { + let _ = rx1.await; + Ok(()) + }).unwrap(); + enqueue_async(&runtime, &engine, move || async move { + let _ = rx2.await; + Ok(()) + }).unwrap(); + + assert_eq!(engine.inflight.load(Ordering::SeqCst), 2); + assert_eq!(engine.dropped.load(Ordering::Relaxed), 0); + + tx1.send(()).unwrap(); + tx2.send(()).unwrap(); +} + +// +// flush_engine +// + +#[test] +fn flush_engine_returns_true_when_idle() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + + assert!(flush_engine(&runtime, &engine, Duration::from_millis(100))); +} + +#[test] +fn flush_engine_returns_false_on_timeout() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + + let (tx, rx) = oneshot::channel::<()>(); + enqueue_async(&runtime, &engine, move || async move { + let _ = rx.await; + Ok(()) + }).unwrap(); + + assert!(!flush_engine(&runtime, &engine, Duration::from_millis(10))); + + tx.send(()).unwrap(); +} + +#[test] +fn flush_engine_wakes_when_inflight_hits_zero() { + let runtime = test_runtime(); + let engine = AsyncEngine::new(); + + let (tx, rx) = oneshot::channel::<()>(); + enqueue_async(&runtime, &engine, move || async move { + let _ = rx.await; + Ok(()) + }).unwrap(); + + // Drop the sender from another thread after a short delay. + let engine2 = engine.clone(); + std::thread::spawn(move || { + std::thread::sleep(Duration::from_millis(30)); + let _ = tx.send(()); + }); + + assert!(flush_engine(&runtime, &engine2, Duration::from_millis(5000))); +} + +// +// lj_logger_set_backpressure +// + +#[test] +fn set_backpressure_null_logger_fails() { + assert!(!unsafe { lj_logger_set_backpressure(ptr::null_mut(), LJ_BACKPRESSURE_DROP, 128) }); +} + +#[test] +fn set_backpressure_invalid_model_fails() { + let logger = test_logger_ptr(); + assert!(!unsafe { lj_logger_set_backpressure(logger, 99, 128) }); + unsafe { lj_logger_free(logger) }; +} + +#[test] +fn set_backpressure_zero_capacity_bounded_fails() { + let logger = test_logger_ptr(); + assert!(!unsafe { lj_logger_set_backpressure(logger, LJ_BACKPRESSURE_DROP, 0) }); + assert!(!unsafe { lj_logger_set_backpressure(logger, LJ_BACKPRESSURE_BLOCK, 0) }); + unsafe { lj_logger_free(logger) }; +} + +#[test] +fn set_backpressure_zero_capacity_unbounded_succeeds() { + let logger = test_logger_ptr(); + assert!(unsafe { lj_logger_set_backpressure(logger, LJ_BACKPRESSURE_UNBOUNDED, 0) }); + unsafe { lj_logger_free(logger) }; +} + +// +// FFI null safety +// + +#[test] +fn log_async_null_logger_returns_false() { + let body = std::ffi::CString::new("hi").unwrap(); + let record = LjLogRecord { + timestamp_unix_ns: 1, severity_number: 9, severity_text: ptr::null(), + body: body.as_ptr(), attributes: ptr::null(), attributes_len: 0, + event_name: ptr::null(), service_name: ptr::null(), scope_name: ptr::null(), + resource_attrs: ptr::null(), resource_attrs_len: 0, + scope_attrs: ptr::null(), scope_attrs_len: 0, + }; + assert!(!unsafe { lj_logger_log_async(ptr::null_mut(), &record) }); +} + +#[test] +fn log_async_null_record_returns_false() { + let logger = test_logger_ptr(); + assert!(!unsafe { lj_logger_log_async(logger, ptr::null()) }); + unsafe { lj_logger_free(logger) }; +} + +#[test] +fn flush_null_logger_returns_false() { + assert!(!unsafe { lj_logger_flush(ptr::null_mut(), 100) }); +} + +#[test] +fn async_errors_null_logger_returns_zero() { + assert_eq!(unsafe { lj_logger_async_errors(ptr::null_mut()) }, 0); +} + +#[test] +fn async_dropped_null_logger_returns_zero() { + assert_eq!(unsafe { lj_logger_async_dropped(ptr::null_mut()) }, 0); +} + +#[test] +fn async_inflight_null_logger_returns_zero() { + assert_eq!(unsafe { lj_logger_async_inflight(ptr::null_mut()) }, 0); +} + +#[test] +fn free_null_logger_does_not_crash() { + unsafe { lj_logger_free(ptr::null_mut()) }; +} diff --git a/liblogjet/tests/unit/batch_ut.rs b/liblogjet/tests/unit/batch_ut.rs index 390a3e1..04325c6 100644 --- a/liblogjet/tests/unit/batch_ut.rs +++ b/liblogjet/tests/unit/batch_ut.rs @@ -5,7 +5,12 @@ use std::time::Duration; use opentelemetry_proto::tonic::common::v1::any_value::Value; -use super::{AsyncEngine, Backend, HttpClient, HttpEndpoint, HttpPool, LjLogRecord, Logger, build_batch_request}; +use super::{ + AsyncEngine, Backend, HttpClient, HttpEndpoint, HttpPool, LjAttribute, LjLogRecord, Logger, + LJ_ATTR_ARRAY, LJ_ATTR_INT, LJ_ATTR_STRING, + build_batch_request, build_request, normalise_grpc_endpoint, parse_http_endpoint, + read_attrs, record_to_log, resolve_resource, resolve_scope, severity_text, triples_to_kvs, +}; fn test_logger(service: &str) -> Logger { let pool = std::sync::Arc::new(HttpPool { @@ -122,3 +127,424 @@ fn timestamps_are_preserved_per_record() { assert_eq!(logs[0].time_unix_nano, 111); assert_eq!(logs[1].time_unix_nano, 222); } + +// +// build_request (single record) +// + +#[test] +fn single_record_has_one_resource_logs_scope_logs_log_record() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); + + let request = build_request(&logger, &rec).expect("build_request"); + + assert_eq!(request.resource_logs.len(), 1); + assert_eq!(request.resource_logs[0].scope_logs.len(), 1); + assert_eq!(request.resource_logs[0].scope_logs[0].log_records.len(), 1); +} + +#[test] +fn single_record_injects_service_name_in_resource() { + let logger = test_logger("my-svc"); + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); + + let request = build_request(&logger, &rec).expect("build_request"); + + let attributes = &request.resource_logs[0].resource.as_ref().expect("resource").attributes; + let svc = attributes.iter().find(|kv| kv.key == "service.name").expect("service.name attribute"); + match svc.value.as_ref().and_then(|v| v.value.as_ref()) { + Some(Value::StringValue(name)) => assert_eq!(name, "my-svc"), + other => panic!("unexpected value: {other:?}"), + } +} + +#[test] +fn single_record_default_scope_name() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); + + let request = build_request(&logger, &rec).expect("build_request"); + + let scope = request.resource_logs[0].scope_logs[0].scope.as_ref().expect("scope"); + assert_eq!(scope.name, "liblogjet"); +} + +#[test] +fn single_record_explicit_scope_name() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let scope_name = CString::new("my-scope").unwrap(); + let mut rec = record(1, &body, None, None); + rec.scope_name = scope_name.as_ptr(); + + let request = build_request(&logger, &rec).expect("build_request"); + + let scope = request.resource_logs[0].scope_logs[0].scope.as_ref().expect("scope"); + assert_eq!(scope.name, "my-scope"); +} + +#[test] +fn single_record_missing_body_is_error() { + let logger = test_logger("svc"); + let mut rec = record(1, c"x", None, None); + rec.body = ptr::null(); + + assert!(build_request(&logger, &rec).is_err()); +} + +#[test] +fn single_record_zero_timestamp_is_replaced_with_now() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + let rec = record(0, &body, None, None); + + let request = build_request(&logger, &rec).expect("build_request"); + + let ts = request.resource_logs[0].scope_logs[0].log_records[0].time_unix_nano; + assert!(ts > 0); +} + +// +// build_batch_request: resource / scope attribute partitioning +// + +#[test] +fn differing_resource_attrs_split_resources() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + + let key_a = CString::new("env").unwrap(); + let val_a = CString::new("prod").unwrap(); + let key_b = CString::new("env").unwrap(); + let val_b = CString::new("staging").unwrap(); + + let attrs_a = [LjAttribute { key: key_a.as_ptr(), value: val_a.as_ptr(), value_type: LJ_ATTR_STRING }]; + let attrs_b = [LjAttribute { key: key_b.as_ptr(), value: val_b.as_ptr(), value_type: LJ_ATTR_STRING }]; + + let mut rec_a = record(1, &body, None, None); + rec_a.resource_attrs = attrs_a.as_ptr(); + rec_a.resource_attrs_len = attrs_a.len(); + + let mut rec_b = record(2, &body, None, None); + rec_b.resource_attrs = attrs_b.as_ptr(); + rec_b.resource_attrs_len = attrs_b.len(); + + let request = build_batch_request(&logger, &[rec_a, rec_b]).expect("batch request"); + assert_eq!(request.resource_logs.len(), 2); +} + +#[test] +fn differing_scope_attrs_split_scopes() { + let logger = test_logger("svc"); + let body = CString::new("hello").unwrap(); + + let key_a = CString::new("library").unwrap(); + let val_a = CString::new("fast").unwrap(); + let key_b = CString::new("library").unwrap(); + let val_b = CString::new("slow").unwrap(); + + let attrs_a = [LjAttribute { key: key_a.as_ptr(), value: val_a.as_ptr(), value_type: LJ_ATTR_STRING }]; + let attrs_b = [LjAttribute { key: key_b.as_ptr(), value: val_b.as_ptr(), value_type: LJ_ATTR_STRING }]; + + let mut rec_a = record(1, &body, None, None); + rec_a.scope_attrs = attrs_a.as_ptr(); + rec_a.scope_attrs_len = attrs_a.len(); + + let mut rec_b = record(2, &body, None, None); + rec_b.scope_attrs = attrs_b.as_ptr(); + rec_b.scope_attrs_len = attrs_b.len(); + + let request = build_batch_request(&logger, &[rec_a, rec_b]).expect("batch request"); + assert_eq!(request.resource_logs.len(), 1); + assert_eq!(request.resource_logs[0].scope_logs.len(), 2); +} + +#[test] +fn mixed_services_and_scopes_form_independent_groups() { + let logger = test_logger("default-svc"); + let body = CString::new("hello").unwrap(); + let svc_a = CString::new("svc-a").unwrap(); + let svc_b = CString::new("svc-b").unwrap(); + let scp_a = CString::new("scope-a").unwrap(); + let scp_b = CString::new("scope-b").unwrap(); + + // 2 services × 2 scopes = 4 groupings + let records = vec![ + record(1, &body, Some(&svc_a), Some(&scp_a)), + record(2, &body, Some(&svc_a), Some(&scp_b)), + record(3, &body, Some(&svc_b), Some(&scp_a)), + record(4, &body, Some(&svc_b), Some(&scp_b)), + ]; + + let request = build_batch_request(&logger, &records).expect("batch request"); + assert_eq!(request.resource_logs.len(), 2); + + let total_scopes: usize = request.resource_logs.iter().map(|rl| rl.scope_logs.len()).sum(); + assert_eq!(total_scopes, 4); + + let total_logs: usize = request.resource_logs.iter() + .flat_map(|rl| rl.scope_logs.iter()) + .map(|sl| sl.log_records.len()) + .sum(); + assert_eq!(total_logs, 4); +} + +// +// read_attrs / triples_to_kvs +// + +#[test] +fn read_attrs_null_pointer_returns_empty() { + let result = read_attrs(ptr::null(), 3).unwrap(); + assert!(result.is_empty()); +} + +#[test] +fn read_attrs_zero_len_returns_empty() { + let attr = LjAttribute { key: c"k".as_ptr(), value: c"v".as_ptr(), value_type: LJ_ATTR_STRING }; + let result = read_attrs(&attr, 0).unwrap(); + assert!(result.is_empty()); +} + +#[test] +fn read_attrs_string_type() { + let attrs = [ + LjAttribute { key: c"key".as_ptr(), value: c"val".as_ptr(), value_type: LJ_ATTR_STRING }, + ]; + let result = read_attrs(attrs.as_ptr(), attrs.len()).unwrap(); + assert_eq!(result.len(), 1); + assert_eq!(result[0], ("key".to_string(), LJ_ATTR_STRING, "val".to_string())); +} + +#[test] +fn read_attrs_int_type() { + let attrs = [ + LjAttribute { key: c"count".as_ptr(), value: c"42".as_ptr(), value_type: LJ_ATTR_INT }, + ]; + let result = read_attrs(attrs.as_ptr(), attrs.len()).unwrap(); + assert_eq!(result[0], ("count".to_string(), LJ_ATTR_INT, "42".to_string())); +} + +#[test] +fn read_attrs_array_type() { + let attrs = [ + LjAttribute { key: c"tags".as_ptr(), value: c"a, b, c".as_ptr(), value_type: LJ_ATTR_ARRAY }, + ]; + let result = read_attrs(attrs.as_ptr(), attrs.len()).unwrap(); + assert_eq!(result[0], ("tags".to_string(), LJ_ATTR_ARRAY, "a, b, c".to_string())); +} + +#[test] +fn read_attrs_null_key_is_error() { + let attrs = [ + LjAttribute { key: ptr::null(), value: c"v".as_ptr(), value_type: LJ_ATTR_STRING }, + ]; + assert!(read_attrs(attrs.as_ptr(), attrs.len()).is_err()); +} + +#[test] +fn triples_to_kvs_string_value() { + let triples = vec![("key".to_string(), LJ_ATTR_STRING, "val".to_string())]; + let kvs = triples_to_kvs(&triples).unwrap(); + assert_eq!(kvs[0].key, "key"); + if let Some(ref v) = kvs[0].value { + if let Some(Value::StringValue(s)) = &v.value { + assert_eq!(s, "val"); + return; + } + } + panic!("unexpected value"); +} + +#[test] +fn triples_to_kvs_int_value() { + let triples = vec![("count".to_string(), LJ_ATTR_INT, "42".to_string())]; + let kvs = triples_to_kvs(&triples).unwrap(); + if let Some(ref v) = kvs[0].value { + if let Some(Value::IntValue(i)) = &v.value { + assert_eq!(*i, 42); + return; + } + } + panic!("unexpected value"); +} + +#[test] +fn triples_to_kvs_array_value() { + let triples = vec![("tags".to_string(), LJ_ATTR_ARRAY, "a, b, c".to_string())]; + let kvs = triples_to_kvs(&triples).unwrap(); + if let Some(ref v) = kvs[0].value { + if let Some(Value::ArrayValue(arr)) = &v.value { + let items: Vec<&str> = arr.values.iter().filter_map(|av| match &av.value { + Some(Value::StringValue(s)) => Some(s.as_str()), + _ => None, + }).collect(); + assert_eq!(items, vec!["a", "b", "c"]); + return; + } + } + panic!("unexpected value"); +} + +#[test] +fn triples_to_kvs_unknown_type_is_error() { + let triples = vec![("key".to_string(), 99, "val".to_string())]; + assert!(triples_to_kvs(&triples).is_err()); +} + +// +// resolve_resource / resolve_scope +// + +#[test] +fn resolve_resource_falls_back_to_logger_service_name() { + let logger = test_logger("default-svc"); + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); // service_name = null + + let (key, attrs) = resolve_resource(&logger, &rec).unwrap(); + assert_eq!(key.0, "default-svc"); + let svc = attrs.iter().find(|kv| kv.key == "service.name").expect("service.name"); + if let Some(ref v) = svc.value { + if let Some(Value::StringValue(s)) = &v.value { + assert_eq!(s, "default-svc"); + return; + } + } + panic!("unexpected service.name value"); +} + +#[test] +fn resolve_resource_empty_service_name_is_error() { + let mut logger = test_logger(""); + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); + + // Records with null service_name that resolve to "" logger default. + logger.service_name = String::new(); + assert!(resolve_resource(&logger, &rec).is_err()); +} + +#[test] +fn resolve_scope_defaults_to_liblogjet() { + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); // scope_name = null + + let (key, scope) = resolve_scope(&rec).unwrap(); + assert_eq!(key.0, "liblogjet"); + assert_eq!(scope.name, "liblogjet"); +} + +// +// record_to_log +// + +#[test] +fn record_to_log_defaults_severity_text_from_number() { + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); // severity_text = null, severity_number = 9 = INFO + + let log = record_to_log(&rec).unwrap(); + assert_eq!(log.severity_text, "INFO"); +} + +#[test] +fn record_to_log_respects_explicit_severity_text() { + let body = CString::new("hello").unwrap(); + let sev = CString::new("WARN").unwrap(); + let mut rec = record(1, &body, None, None); + rec.severity_text = sev.as_ptr(); + + let log = record_to_log(&rec).unwrap(); + assert_eq!(log.severity_text, "WARN"); +} + +#[test] +fn record_to_log_defaults_event_name_to_empty() { + let body = CString::new("hello").unwrap(); + let rec = record(1, &body, None, None); // event_name = null + + let log = record_to_log(&rec).unwrap(); + assert_eq!(log.event_name, ""); +} + +#[test] +fn record_to_log_zero_timestamp_replaced_with_now() { + let body = CString::new("hello").unwrap(); + let rec = record(0, &body, None, None); + + let log = record_to_log(&rec).unwrap(); + assert!(log.time_unix_nano > 0); +} + +// +// severity_text +// + +#[test] +fn severity_text_maps_correctly() { + assert_eq!(severity_text(1), "TRACE"); + assert_eq!(severity_text(4), "TRACE"); + assert_eq!(severity_text(5), "DEBUG"); + assert_eq!(severity_text(9), "INFO"); + assert_eq!(severity_text(13), "WARN"); + assert_eq!(severity_text(17), "ERROR"); + assert_eq!(severity_text(21), "FATAL"); +} + +// +// parse_http_endpoint / normalise_grpc_endpoint +// + +#[test] +fn parse_http_host_port_defaults_path() { + let ep = parse_http_endpoint("127.0.0.1:4318").unwrap(); + assert_eq!(ep.authority, "127.0.0.1:4318"); + assert_eq!(ep.host_header, "127.0.0.1:4318"); + assert_eq!(ep.path, "/v1/logs"); +} + +#[test] +fn parse_http_with_custom_path() { + let ep = parse_http_endpoint("127.0.0.1:4318/custom/path").unwrap(); + assert_eq!(ep.authority, "127.0.0.1:4318"); + assert_eq!(ep.path, "/custom/path"); +} + +#[test] +fn parse_http_scheme_is_stripped() { + let ep = parse_http_endpoint("http://127.0.0.1:4318").unwrap(); + assert_eq!(ep.authority, "127.0.0.1:4318"); + assert_eq!(ep.path, "/v1/logs"); +} + +#[test] +fn parse_http_with_scheme_and_path() { + let ep = parse_http_endpoint("http://127.0.0.1:4318/p").unwrap(); + assert_eq!(ep.authority, "127.0.0.1:4318"); + assert_eq!(ep.path, "/p"); +} + +#[test] +fn parse_https_is_rejected() { + assert!(parse_http_endpoint("https://127.0.0.1:4318").is_err()); +} + +#[test] +fn parse_http_empty_is_error() { + assert!(parse_http_endpoint("").is_err()); +} + +#[test] +fn normalise_grpc_adds_http_scheme() { + assert_eq!(normalise_grpc_endpoint("127.0.0.1:4317"), "http://127.0.0.1:4317"); +} + +#[test] +fn normalise_grpc_preserves_existing_scheme() { + assert_eq!(normalise_grpc_endpoint("http://127.0.0.1:4317"), "http://127.0.0.1:4317"); +} From 84e6fe775fef2631104de819fa417789122fe35a Mon Sep 17 00:00:00 2001 From: Bo Maryniuk Date: Thu, 23 Jul 2026 15:32:57 +0200 Subject: [PATCH 21/21] Lintfixes --- liblogjet/tests/unit/batch_ut.rs | 20 ++++++++------------ 1 file changed, 8 insertions(+), 12 deletions(-) diff --git a/liblogjet/tests/unit/batch_ut.rs b/liblogjet/tests/unit/batch_ut.rs index 04325c6..ac11f21 100644 --- a/liblogjet/tests/unit/batch_ut.rs +++ b/liblogjet/tests/unit/batch_ut.rs @@ -351,12 +351,11 @@ fn triples_to_kvs_string_value() { let triples = vec![("key".to_string(), LJ_ATTR_STRING, "val".to_string())]; let kvs = triples_to_kvs(&triples).unwrap(); assert_eq!(kvs[0].key, "key"); - if let Some(ref v) = kvs[0].value { - if let Some(Value::StringValue(s)) = &v.value { + if let Some(ref v) = kvs[0].value + && let Some(Value::StringValue(s)) = &v.value { assert_eq!(s, "val"); return; } - } panic!("unexpected value"); } @@ -364,12 +363,11 @@ fn triples_to_kvs_string_value() { fn triples_to_kvs_int_value() { let triples = vec![("count".to_string(), LJ_ATTR_INT, "42".to_string())]; let kvs = triples_to_kvs(&triples).unwrap(); - if let Some(ref v) = kvs[0].value { - if let Some(Value::IntValue(i)) = &v.value { + if let Some(ref v) = kvs[0].value + && let Some(Value::IntValue(i)) = &v.value { assert_eq!(*i, 42); return; } - } panic!("unexpected value"); } @@ -377,8 +375,8 @@ fn triples_to_kvs_int_value() { fn triples_to_kvs_array_value() { let triples = vec![("tags".to_string(), LJ_ATTR_ARRAY, "a, b, c".to_string())]; let kvs = triples_to_kvs(&triples).unwrap(); - if let Some(ref v) = kvs[0].value { - if let Some(Value::ArrayValue(arr)) = &v.value { + if let Some(ref v) = kvs[0].value + && let Some(Value::ArrayValue(arr)) = &v.value { let items: Vec<&str> = arr.values.iter().filter_map(|av| match &av.value { Some(Value::StringValue(s)) => Some(s.as_str()), _ => None, @@ -386,7 +384,6 @@ fn triples_to_kvs_array_value() { assert_eq!(items, vec!["a", "b", "c"]); return; } - } panic!("unexpected value"); } @@ -409,12 +406,11 @@ fn resolve_resource_falls_back_to_logger_service_name() { let (key, attrs) = resolve_resource(&logger, &rec).unwrap(); assert_eq!(key.0, "default-svc"); let svc = attrs.iter().find(|kv| kv.key == "service.name").expect("service.name"); - if let Some(ref v) = svc.value { - if let Some(Value::StringValue(s)) = &v.value { + if let Some(ref v) = svc.value + && let Some(Value::StringValue(s)) = &v.value { assert_eq!(s, "default-svc"); return; } - } panic!("unexpected service.name value"); }