Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/KurrentDB.Core/ClusterVNodeStartup.cs
Original file line number Diff line number Diff line change
Expand Up @@ -314,7 +314,7 @@ public void ConfigureServices(IServiceCollection services) {
services.AddGrpcReflection();
#endif

services.AddDuckDb();
services.AddDuckDb(_metricsConfiguration.ServiceName);

// Ask the node itself to add DI registrations
_configureNodeServices(services);
Expand Down
70 changes: 70 additions & 0 deletions src/KurrentDB.Core/DuckDB/DuckDBCpuMetrics.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
// Copyright (c) Kurrent, Inc and/or licensed to Kurrent, Inc under one or more agreements.
// Kurrent, Inc licenses this file to you under the Kurrent License v1 (see LICENSE.md).

using System;
using System.Collections.Generic;
using System.Diagnostics.Metrics;

namespace KurrentDB.Core.DuckDB;

// Attributes CPU consumed by DuckDB operations executed on KurrentDB threads.
// DuckDB also schedules work onto its own native worker threads; that share is not visible
// to caller-side measurement and is reported separately once KurrentDB owns those workers.
public class DuckDBCpuMetrics {
public const string MeterName = "KurrentDB.DuckDB";

public static class Activities {
public const string Query = "query";
public const string Read = "read";
public const string Commit = "commit";
public const string Checkpoint = "checkpoint";
}

private static readonly KeyValuePair<string, object> SourceTag = new("source", "caller");

private readonly Counter<double> _cpuSeconds;

// Reads the calling thread's cumulative CPU time in nanoseconds. Null when per-thread CPU
// time is unavailable on this platform, in which case measurement is a no-op. Injectable so
// tests can supply a deterministic source instead of relying on real per-thread CPU accounting.
private readonly Func<long> _currentCpuNanoseconds;

public DuckDBCpuMetrics(Meter meter, string serviceName, Func<long> currentCpuNanoseconds = null) {
_cpuSeconds = meter.CreateCounter<double>(
$"{serviceName}.duckdb.cpu.seconds",
description: "CPU time consumed by DuckDB operations on KurrentDB threads, in seconds");
_currentCpuNanoseconds = currentCpuNanoseconds
?? (ThreadCpuTime.IsSupported ? () => ThreadCpuTime.CurrentNanoseconds : (Func<long>)null);
}

public CpuScope Measure(string activity) => new(this, activity);

// A ref struct so it cannot live across an await: the CPU delta is only valid when start
// and stop are read on the same thread.
public readonly ref struct CpuScope {
private readonly DuckDBCpuMetrics _metrics;
private readonly string _activity;
private readonly long _startNanoseconds;

internal CpuScope(DuckDBCpuMetrics metrics, string activity) {
if (metrics._currentCpuNanoseconds is null)
return; // per-thread CPU time unavailable on this platform: no-op

_metrics = metrics;
_activity = activity;
_startNanoseconds = metrics._currentCpuNanoseconds();
}

public void Dispose() {
if (_metrics is null)
return;

var elapsedNanoseconds = _metrics._currentCpuNanoseconds!() - _startNanoseconds;
if (elapsedNanoseconds > 0)
_metrics._cpuSeconds.Add(
elapsedNanoseconds / 1e9,
new KeyValuePair<string, object>("activity", _activity),
SourceTag);
}
}
}
7 changes: 6 additions & 1 deletion src/KurrentDB.Core/DuckDB/InjectionExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// Kurrent, Inc licenses this file to you under the Kurrent License v1 (see LICENSE.md).

using System;
using System.Diagnostics.Metrics;
using System.Threading.Tasks;
using Kurrent.Quack.ConnectionPool;
using KurrentDB.DuckDB;
Expand All @@ -15,12 +16,16 @@
namespace KurrentDB.Core.DuckDB;

public static class InjectionExtensions {
public static IServiceCollection AddDuckDb(this IServiceCollection services) {
public static IServiceCollection AddDuckDb(this IServiceCollection services, string serviceName) {
services.AddSingleton<DuckDBConnectionPoolLifetime>();
services.AddHostedService(sp => sp.GetRequiredService<DuckDBConnectionPoolLifetime>());
services.AddSingleton<DuckDBConnectionPool>(sp => sp.GetRequiredService<DuckDBConnectionPoolLifetime>().Shared);
services.AddSingleton<DuckDbConnectionPoolMiddleware>();
services.AddSingleton<ConnectionInterceptor>(CreatePoolPerConnectionInterceptor);
// serviceName is passed in (not resolved from DI) because MetricsConfiguration is not
// available in every collection AddDuckDb is used from; this keeps the meter named
// consistently with the rest of the metrics pipeline, including legacy "eventstore" naming.
services.AddSingleton(new DuckDBCpuMetrics(new Meter(DuckDBCpuMetrics.MeterName, "1.0.0"), serviceName));
return services;
}

Expand Down
63 changes: 63 additions & 0 deletions src/KurrentDB.Core/DuckDB/ThreadCpuTime.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,63 @@
// Copyright (c) Kurrent, Inc and/or licensed to Kurrent, Inc under one or more agreements.
// Kurrent, Inc licenses this file to you under the Kurrent License v1 (see LICENSE.md).

using System;
using System.Runtime.InteropServices;

namespace KurrentDB.Core.DuckDB;

// Reads the cumulative CPU time consumed by the calling thread.
// A delta between two readings is only meaningful when both are taken on the same thread.
internal static class ThreadCpuTime {
// CLOCK_THREAD_CPUTIME_ID differs per libc: bits/time.h on Linux, sys/_types/_clockid_t on macOS
private const int ClockThreadCpuTimeIdLinux = 3;
private const int ClockThreadCpuTimeIdMacOS = 16;

public static readonly bool IsSupported = Detect();

public static long CurrentNanoseconds => OperatingSystem.IsWindows()
? GetWindowsThreadCpuNanoseconds()
: GetPosixThreadCpuNanoseconds();

private static long GetPosixThreadCpuNanoseconds() {
var clockId = OperatingSystem.IsLinux() ? ClockThreadCpuTimeIdLinux : ClockThreadCpuTimeIdMacOS;
return clock_gettime(clockId, out var ts) == 0
? ts.Seconds * 1_000_000_000L + ts.Nanoseconds
: 0;
}

private static long GetWindowsThreadCpuNanoseconds() {
// GetThreadTimes reports in 100ns units, accrued at scheduler-quantum granularity.
// Cumulative totals are statistically accurate; very short individual deltas are not.
return GetThreadTimes(GetCurrentThread(), out _, out _, out var kernelTime, out var userTime)
? (kernelTime + userTime) * 100
: 0;
}

private static bool Detect() {
if (!OperatingSystem.IsWindows() && !OperatingSystem.IsLinux() && !OperatingSystem.IsMacOS())
return false;

try {
_ = CurrentNanoseconds;
return true;
} catch (Exception e) when (e is DllNotFoundException or EntryPointNotFoundException) {
return false;
}
}

[StructLayout(LayoutKind.Sequential)]
private struct Timespec {
public nint Seconds;
public nint Nanoseconds;
}

[DllImport("libc")]
private static extern int clock_gettime(int clockId, out Timespec ts);

[DllImport("kernel32.dll", ExactSpelling = true)]
private static extern nint GetCurrentThread();

[DllImport("kernel32.dll", ExactSpelling = true)]
private static extern bool GetThreadTimes(nint thread, out long creationTime, out long exitTime, out long kernelTime, out long userTime);
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
// Copyright (c) Kurrent, Inc and/or licensed to Kurrent, Inc under one or more agreements.
// Kurrent, Inc licenses this file to you under the Kurrent License v1 (see LICENSE.md).

using System.Diagnostics;
using System.Diagnostics.Metrics;
using KurrentDB.Core.DuckDB;

namespace KurrentDB.SecondaryIndexing.Tests.Diagnostics;

public class DuckDBCpuMetricsTests {
[Fact]
public void busy_scope_records_cpu_seconds_with_activity_and_source_tags() {
using var meter = new Meter("test");
var metrics = new DuckDBCpuMetrics(meter, "kurrentdb");

List<(double Value, KeyValuePair<string, object?>[] Tags)> measurements = [];
using var listener = Listen(meter, measurements);

using (metrics.Measure(DuckDBCpuMetrics.Activities.Commit)) {
// busy spin long enough to accrue CPU past Windows' quantum-granular thread accounting
var stopwatch = Stopwatch.StartNew();
while (stopwatch.ElapsedMilliseconds < 100) {
}
}

var measurement = Assert.Single(measurements);
Assert.InRange(measurement.Value, 0.001, 30);
Assert.Contains(measurement.Tags, t => t is { Key: "activity", Value: "commit" });
Assert.Contains(measurement.Tags, t => t is { Key: "source", Value: "caller" });
}

[Fact]
public void idle_scope_records_at_most_negligible_cpu() {
using var meter = new Meter("test");
var metrics = new DuckDBCpuMetrics(meter, "kurrentdb");

List<(double Value, KeyValuePair<string, object?>[] Tags)> measurements = [];
using var listener = Listen(meter, measurements);

using (metrics.Measure(DuckDBCpuMetrics.Activities.Read)) {
Thread.Sleep(100);
}

Assert.True(measurements.Sum(m => m.Value) < 0.05, $"expected near-zero CPU, got {measurements.Sum(m => m.Value)}s");
}

// Deterministic: a fake CPU-time source replaces real per-thread accounting, so the assertion does
// not depend on the scope accruing measurable CPU (which can round to zero on small/fast work,
// especially under Windows' scheduler-quantum-granular GetThreadTimes).
[Theory]
[InlineData(DuckDBCpuMetrics.Activities.Query)]
[InlineData(DuckDBCpuMetrics.Activities.Commit)]
public void measure_records_exact_caller_cpu_delta_with_tags(string activity) {
using var meter = new Meter("test");
var cpuNanoseconds = 1_000_000_000L;
var metrics = new DuckDBCpuMetrics(meter, "kurrentdb", () => cpuNanoseconds);

List<(double Value, KeyValuePair<string, object?>[] Tags)> measurements = [];
using var listener = Listen(meter, measurements);

using (metrics.Measure(activity)) {
cpuNanoseconds += 250_000_000; // +0.25s of caller CPU
}

var measurement = Assert.Single(measurements);
Assert.Equal(0.25, measurement.Value, precision: 9);
Assert.Contains(measurement.Tags, t => t.Key == "activity" && (string?)t.Value == activity);
Assert.Contains(measurement.Tags, t => t is { Key: "source", Value: "caller" });
}

[Fact]
public void measure_with_zero_cpu_delta_records_nothing() {
using var meter = new Meter("test");
var cpuNanoseconds = 5_000_000_000L;
var metrics = new DuckDBCpuMetrics(meter, "kurrentdb", () => cpuNanoseconds);

List<(double Value, KeyValuePair<string, object?>[] Tags)> measurements = [];
using var listener = Listen(meter, measurements);

using (metrics.Measure(DuckDBCpuMetrics.Activities.Query)) {
// no CPU accrues during the scope
}

Assert.Empty(measurements);
}

private static MeterListener Listen(Meter meter, List<(double, KeyValuePair<string, object?>[])> measurements) {
var listener = new MeterListener();
listener.InstrumentPublished = (instrument, l) => {
if (instrument.Meter == meter && instrument.Name == "kurrentdb.duckdb.cpu.seconds")
l.EnableMeasurementEvents(instrument);
};
listener.SetMeasurementEventCallback<double>(
(_, value, tags, _) => measurements.Add((value, tags.ToArray())));
listener.Start();
return listener;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using DotNext;
using Kurrent.Quack;
using KurrentDB.Core.Data;
using KurrentDB.Core.DuckDB;
using KurrentDB.Core.Index.Hashes;
using KurrentDB.Core.Tests.Fakes;
using KurrentDB.SecondaryIndexing.Indexes.Default;
Expand Down Expand Up @@ -211,7 +212,8 @@ public DefaultIndexProcessorTests() {

var publisher = new FakePublisher();

_processor = new(DuckDb, publisher, hasher, new("test"), NullLoggerFactory.Instance);
_processor = new(DuckDb, publisher, hasher, new("test"), NullLoggerFactory.Instance,
new DuckDBCpuMetrics(new("test"), "kurrentdb"));
}

public override ValueTask DisposeAsync() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// Kurrent, Inc licenses this file to you under the Kurrent License v1 (see LICENSE.md).

using KurrentDB.Core.Data;
using KurrentDB.Core.DuckDB;
using KurrentDB.Core.Index.Hashes;
using KurrentDB.Core.Tests.Fakes;
using KurrentDB.SecondaryIndexing.Indexes.Default;
Expand All @@ -22,9 +23,10 @@ protected IndexTestBase() {
var hasher = new CompositeHasher<string>(new XXHashUnsafe(), new Murmur3AUnsafe());
var publisher = new FakePublisher();

_processor = new(DuckDb, publisher, hasher, new("test"), NullLoggerFactory.Instance);
var cpuMetrics = new DuckDBCpuMetrics(new("test"), "kurrentdb");
_processor = new(DuckDb, publisher, hasher, new("test"), NullLoggerFactory.Instance, cpuMetrics);

Sut = new(DuckDb, _processor, _readIndexStub.ReadIndex);
Sut = new(DuckDb, _processor, _readIndexStub.ReadIndex, cpuMetrics);
}

protected void IndexEvents(ResolvedEvent[] events, bool shouldCommit) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using Kurrent.Quack;
using Kurrent.Quack.ConnectionPool;
using KurrentDB.Core.Data;
using KurrentDB.Core.DuckDB;
using KurrentDB.Core.Services.Storage.ReaderIndex;
using KurrentDB.SecondaryIndexing.Indexes.Default;
using KurrentDB.SecondaryIndexing.Storage;
Expand All @@ -16,8 +17,9 @@ namespace KurrentDB.SecondaryIndexing.Indexes.Category;
internal class CategoryIndexReader(
DuckDBConnectionPool sharedPool,
DefaultIndexProcessor processor,
IReadIndex<string> index)
: SecondaryIndexReaderBase(sharedPool, index) {
IReadIndex<string> index,
DuckDBCpuMetrics cpuMetrics)
: SecondaryIndexReaderBase(sharedPool, index, cpuMetrics) {
protected override string GetId(string indexName) =>
CategoryIndex.TryParseCategoryName(indexName, out var categoryName)
? categoryName
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@
using KurrentDB.Common.Configuration;
using KurrentDB.Core.Bus;
using KurrentDB.Core.Data;
using KurrentDB.Core.DuckDB;
using KurrentDB.Core.Index.Hashes;
using KurrentDB.Core.Messages;
using KurrentDB.Core.Services;
Expand All @@ -33,6 +34,7 @@ internal class DefaultIndexProcessor : Disposable, ISecondaryIndexProcessor {
private readonly ILongHasher<string> _hasher;
private readonly ILogger<DefaultIndexProcessor> _log;
private readonly BufferedView _appender;
private readonly DuckDBCpuMetrics _cpuMetrics;
private Atomic<TFPos> _lastPosition;

public TFPos LastIndexedPosition {
Expand All @@ -47,10 +49,12 @@ public DefaultIndexProcessor(
[FromKeyedServices(SecondaryIndexingConstants.InjectionKey)]
Meter meter,
ILoggerFactory loggerFactory,
DuckDBCpuMetrics cpuMetrics,
MetricsConfiguration? metricsConfiguration = null,
TimeProvider? clock = null
) {
_connection = db.Open();
_cpuMetrics = cpuMetrics;
_log = loggerFactory.CreateLogger<DefaultIndexProcessor>();
_appender = new(_connection, "idx_all", "log_position", DefaultIndexViewName);
var serviceName = metricsConfiguration?.ServiceName ?? "kurrentdb";
Expand Down Expand Up @@ -153,6 +157,7 @@ public void Commit() {

try {
using var duration = Tracker.StartCommitDuration();
using var cpu = _cpuMetrics.Measure(DuckDBCpuMetrics.Activities.Commit);
_appender.Flush();
} catch (Exception e) {
_log.LogError(e, "Failed to commit records to index at log position {LogPosition}", LastIndexedPosition);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using Kurrent.Quack;
using Kurrent.Quack.ConnectionPool;
using KurrentDB.Core.Data;
using KurrentDB.Core.DuckDB;
using KurrentDB.Core.Services;
using KurrentDB.Core.Services.Storage.ReaderIndex;
using KurrentDB.SecondaryIndexing.Storage;
Expand All @@ -14,8 +15,9 @@ namespace KurrentDB.SecondaryIndexing.Indexes.Default;
internal class DefaultIndexReader(
DuckDBConnectionPool sharedPool,
DefaultIndexProcessor processor,
IReadIndex<string> index
) : SecondaryIndexReaderBase(sharedPool, index) {
IReadIndex<string> index,
DuckDBCpuMetrics cpuMetrics
) : SecondaryIndexReaderBase(sharedPool, index, cpuMetrics) {
protected override string GetId(string indexName) => string.Empty;

protected override List<IndexQueryRecord> GetDbRecordsForwards(DuckDBConnectionPool db,
Expand Down
Loading
Loading