Skip to content

Commit 2624b52

Browse files
committed
src: add fast api calls to push span strings
This commit introduces performance optimizations for tracing span attribute handling by adding two new fast API calls: 1. FastPushSpanDataString - Optimized version of the existing string push method 2. FastPushSpanDataString3 - New method to efficiently handle three string values in a single call Key changes include: - Avoided JavaScript string concatenation which produces non-flattened V8 strings that cannot trigger fast API paths - Implemented direct passing of individual string components to C++ where concatenation can happen after the fast API boundary - Refactored HTTP URL construction in both client and server to leverage this optimization - Improved span context handling by storing trace ID, span ID, and parent span ID as separate attributes rather than a single concatenated string These optimizations significantly improve performance in high load scenarios: - Up to 3.24% higher throughput in maximum load tests - Up to 57.75% lower latency at P99.9 under constant high rate (50k req/sec) - Substantial improvements across all high percentile latencies (P95-P99.999) - Most dramatic gains observed in tail latencies under sustained heavy load === Benchmark Summary === Benchmark Type: wrk2 (constant rate) Old Version: ./nsolid_baseline New Version: ./nsolid_fast_push_string Iterations: 50 Connections: 10 Duration: 60s Rate: 40k req/sec +------------------+-------------+-------------+------------+-----+ | Metric | Old Version | New Version | Difference | Sig | +------------------+-------------+-------------+------------+-----+ | Avg Latency (ms) | 2.58 | 2.34 | N/A | | | P50 Latency (ms) | 1.09 | 1.10 | +0.80% | *** | | P90 Latency (ms) | 2.22 | 2.20 | -0.63% | *** | | P99 Latency (ms) | 3.09 | 2.99 | -3.31% | *** | | Avg Req/Sec | 39,992.50 | 39,992.53 | +0.00% | | +------------------+-------------+-------------+------------+-----+ === Benchmark Summary === Benchmark Type: wrk2 (constant rate) Old Version: ./nsolid_baseline New Version: ./nsolid_fast_push_string Iterations: 50 Connections: 10 Duration: 60s Rate: 50k req/sec +------------------+-------------+-------------+------------+-----+ | Metric | Old Version | New Version | Difference | Sig | +------------------+-------------+-------------+------------+-----+ | Avg Latency (ms) | 9.92 | 5.20 | N/A | | | P50 Latency (ms) | 0.95 | 0.94 | -0.54% | | | P90 Latency (ms) | 2.54 | 2.35 | -7.47% | *** | | P99 Latency (ms) | 12.00 | 5.58 | -53.49% | *** | | Avg Req/Sec | 49,990.78 | 49,990.72 | -0.00% | | +------------------+-------------+-------------+------------+-----+ === Benchmark Summary === Benchmark Type: wrk (maximum throughput) Old Version: ./nsolid_baseline New Version: ./nsolid_fast_push_string Iterations: 50 Connections: 10 Duration: 60s Threads: 2 +------------------+-------------+-------------+------------+-----+ | Metric | Old Version | New Version | Difference | Sig | +------------------+-------------+-------------+------------+-----+ | Avg Latency (ms) | 0.65 | 0.64 | N/A | | | P50 Latency (ms) | 0.17 | 0.16 | -3.48% | *** | | P90 Latency (ms) | 0.33 | 0.32 | -2.30% | *** | | P99 Latency (ms) | 0.36 | 0.35 | -3.33% | *** | | Avg Req/Sec | 52,398.20 | 54,094.55 | +3.24% | *** | +------------------+-------------+-------------+------------+-----+ PR-URL: #289 Reviewed-By: Juan José Arboleda <[email protected]>
1 parent eb73b40 commit 2624b52

File tree

8 files changed

+181
-48
lines changed

8 files changed

+181
-48
lines changed

lib/_http_client.js

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -481,10 +481,9 @@ function ClientRequest(input, options, cb) {
481481
api.context.with(api.trace.setSpan(api.context.active(), span), () => {
482482
fn.call(this);
483483
// At this point we know the request is actually being initiated
484-
const u = `${protocol}//${this.getHeader('host')}${this.path}`;
485484
span._pushSpanDataString(kSpanHttpMethod, method);
486485
span._pushSpanDataString(kSpanHttpProtocolVersion, '1.1');
487-
span._pushSpanDataString(kSpanHttpReqUrl, u);
486+
span._pushSpanDataString3(kSpanHttpReqUrl, protocol, this.getHeader('host') || 'localhost', this.path);
488487
this.prependOnceListener('error', requestOnError);
489488
this.once('close', requestOnClose);
490489
}, this);

lib/_http_server.js

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1113,8 +1113,7 @@ function parserOnIncoming(server, socket, state, req, keepAlive) {
11131113
let api;
11141114
let span;
11151115
if (generateSpan(kSpanHttpServer)) {
1116-
const protocol = req.connection.encrypted ? 'https' : 'http';
1117-
const u = `${protocol}://${req.headers.host || 'localhost'}${req.originalUrl || req.url}`;
1116+
const protocol = req.connection.encrypted ? 'https:' : 'http:';
11181117
api = getApi();
11191118
const tracer = api.trace.getTracer('http');
11201119
const ctxt = extractSpanContextFromHttpHeaders(api.ROOT_CONTEXT,
@@ -1128,7 +1127,7 @@ function parserOnIncoming(server, socket, state, req, keepAlive) {
11281127
req[nsolid_span_id_s] = span;
11291128
span._pushSpanDataString(kSpanHttpMethod, req.method);
11301129
span._pushSpanDataString(kSpanHttpProtocolVersion, req.httpVersion);
1131-
span._pushSpanDataString(kSpanHttpReqUrl, u);
1130+
span._pushSpanDataString3(kSpanHttpReqUrl, protocol, req.headers.host || 'localhost', req.originalUrl || req.url);
11321131
}
11331132

11341133
if (req.upgrade) {

lib/internal/otel/trace.js

Lines changed: 16 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,6 @@ const {
88
const binding = internalBinding('nsolid_api');
99
const { getSpanId,
1010
getTraceId,
11-
pushSpanDataString,
1211
nsolid_consts } = binding;
1312

1413
const {
@@ -38,7 +37,7 @@ class SpanContext {
3837
}
3938
}
4039

41-
function Span(internalId, ids_str, spanContext, startTime, type, kind, links) {
40+
function Span(internalId, parentSpanId, spanContext, startTime, type, kind, links) {
4241
this._spanContext = spanContext;
4342
this.ended = false;
4443
this.internalId = internalId;
@@ -56,7 +55,11 @@ function Span(internalId, ids_str, spanContext, startTime, type, kind, links) {
5655
this._pushSpanDataUint64(nsolid_consts.kSpanKind, this.kind);
5756
}
5857

59-
this._pushSpanDataString(nsolid_consts.kSpanOtelIds, ids_str);
58+
this._pushSpanDataString(nsolid_consts.kSpanTraceId, spanContext.traceId);
59+
this._pushSpanDataString(nsolid_consts.kSpanSpanId, spanContext.spanId);
60+
if (parentSpanId) {
61+
this._pushSpanDataString(nsolid_consts.kSpanParentSpanId, parentSpanId);
62+
}
6063
}
6164
}
6265

@@ -210,7 +213,15 @@ Span.prototype._pushSpanDataDouble = function(type, name) {
210213

211214
Span.prototype._pushSpanDataString = function(type, name) {
212215
if (this._isSampled()) {
213-
pushSpanDataString(this.internalId, type, name);
216+
binding.pushSpanDataString(this.internalId, type, name);
217+
}
218+
219+
return this;
220+
};
221+
222+
Span.prototype._pushSpanDataString3 = function(type, val1, val2, val3) {
223+
if (this._isSampled()) {
224+
binding.pushSpanDataString3(this.internalId, type, val1, val2, val3);
214225
}
215226

216227
return this;
@@ -240,20 +251,17 @@ class Tracer {
240251
}
241252
}
242253

243-
let ids_str;
244254
let traceState;
245255
let traceId;
246256

247257
const spanId = getSpanId();
248258
if (!parentContext) {
249259
// New root span.
250260
traceId = getTraceId();
251-
ids_str = `${traceId}:${spanId}`;
252261
} else {
253262
// New child span.
254263
traceId = parentContext.traceId;
255264
traceState = parentContext.traceState;
256-
ids_str = `${traceId}:${spanId}:${parentContext.spanId}`;
257265
}
258266

259267
const internalId = newInternalSpanId();
@@ -269,7 +277,7 @@ class Tracer {
269277

270278
const startTime = options.startTime || now();
271279
const span = new Span(internalId,
272-
ids_str,
280+
parentContext?.spanId,
273281
spanContext,
274282
startTime,
275283
options.type || nsolid_consts.kSpanCustom,

src/node_external_reference.h

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,19 @@ using CFunctionBufferCopy =
9494
uint32_t source_start,
9595
uint32_t to_copy);
9696

97+
using CFunctionPushSpanDataString =
98+
void (*)(v8::Local<v8::Object> receiver,
99+
uint32_t trace_id,
100+
uint32_t type,
101+
const v8::FastOneByteString& val);
102+
using CFunctionPushSpanDataString3 =
103+
void (*)(v8::Local<v8::Object> receiver,
104+
uint32_t trace_id,
105+
uint32_t type,
106+
const v8::FastOneByteString& val1,
107+
const v8::FastOneByteString& val2,
108+
const v8::FastOneByteString& val3);
109+
97110
// This class manages the external references from the V8 heap
98111
// to the C++ addresses in Node.js.
99112
class ExternalReferenceRegistry {
@@ -125,6 +138,8 @@ class ExternalReferenceRegistry {
125138
V(CFunctionWithBool) \
126139
V(CFunctionBufferCopy) \
127140
V(CFunctionWriteString) \
141+
V(CFunctionPushSpanDataString) \
142+
V(CFunctionPushSpanDataString3) \
128143
V(const v8::CFunctionInfo*) \
129144
V(v8::FunctionCallback) \
130145
V(v8::AccessorNameGetterCallback) \

src/nsolid/nsolid_api.cc

Lines changed: 103 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -41,11 +41,11 @@ using nsuv::ns_timer;
4141

4242
using tracing::Span;
4343
using tracing::SpanItem;
44-
using tracing::SpanPropBase;
4544

4645
using v8::ArrayBuffer;
4746
using v8::BackingStore;
4847
using v8::Context;
48+
using v8::FastOneByteString;
4949
using v8::Float64Array;
5050
using v8::Function;
5151
using v8::FunctionCallbackInfo;
@@ -2364,34 +2364,94 @@ void BindingData::PushSpanDataUint64Impl(BindingData* data,
23642364
SpanItem{ trace_id, envinst->thread_id(), std::move(prop) });
23652365
}
23662366

2367-
2368-
static void PushSpanDataString(const FunctionCallbackInfo<Value>& args) {
2367+
void BindingData::SlowPushSpanDataString(
2368+
const FunctionCallbackInfo<Value>& args) {
23692369
Isolate* isolate = args.GetIsolate();
2370-
EnvInst* envinst = EnvInst::GetEnvLocalInst(isolate);
2371-
DCHECK_NE(envinst, nullptr);
23722370
DCHECK_EQ(args.Length(), 3);
23732371
DCHECK(args[0]->IsUint32());
23742372
DCHECK(args[1]->IsUint32());
23752373
DCHECK(args[2]->IsString());
23762374
uint32_t trace_id = args[0].As<Uint32>()->Value();
2377-
Span::PropType prop_type =
2378-
static_cast<Span::PropType>(args[1].As<Uint32>()->Value());
2379-
std::unique_ptr<SpanPropBase> prop;
2375+
uint32_t type = args[1].As<Uint32>()->Value();
23802376
Local<String> value_s = args[2].As<String>();
2381-
if (prop_type == Span::kSpanOtelIds && value_s->IsOneByte()) {
2382-
char ids[67];
2383-
int len = value_s->WriteOneByte(isolate, reinterpret_cast<uint8_t*>(ids));
2384-
ids[len] = '\0';
2385-
prop = Span::createSpanProp<std::string>(prop_type, ids);
2386-
} else {
2387-
String::Utf8Value value_str(isolate, value_s);
2388-
prop = Span::createSpanProp<std::string>(prop_type, *value_str);
2389-
}
2377+
BindingData* data = FromJSObject<BindingData>(args.This());
2378+
const std::string val = *String::Utf8Value(isolate, value_s);
2379+
PushSpanDataStringImpl(data, trace_id, type, val);
2380+
}
2381+
23902382

2391-
SpanItem item = { trace_id,
2392-
envinst->thread_id(),
2393-
std::move(prop) };
2394-
EnvList::Inst()->GetTracer()->pushSpanData(std::move(item));
2383+
void BindingData::FastPushSpanDataString(v8::Local<v8::Object> receiver,
2384+
uint32_t trace_id,
2385+
uint32_t type,
2386+
const FastOneByteString& val) {
2387+
PushSpanDataStringImpl(FromJSObject<BindingData>(receiver),
2388+
trace_id,
2389+
type,
2390+
std::string(val.data, val.length));
2391+
}
2392+
2393+
2394+
void BindingData::PushSpanDataStringImpl(BindingData* data,
2395+
uint32_t trace_id,
2396+
uint32_t type,
2397+
const std::string& val) {
2398+
Span::PropType prop_type = static_cast<Span::PropType>(type);
2399+
auto prop = Span::createSpanProp<std::string>(prop_type, val);
2400+
EnvInst* envinst = data->env()->envinst_.get();
2401+
EnvList::Inst()->GetTracer()->pushSpanData(
2402+
SpanItem{ trace_id, envinst->thread_id(), std::move(prop) });
2403+
}
2404+
2405+
2406+
void BindingData::SlowPushSpanDataString3(
2407+
const FunctionCallbackInfo<Value>& args) {
2408+
Isolate* isolate = args.GetIsolate();
2409+
DCHECK_EQ(args.Length(), 5);
2410+
DCHECK(args[0]->IsUint32());
2411+
DCHECK(args[1]->IsUint32());
2412+
DCHECK(args[2]->IsString());
2413+
DCHECK(args[3]->IsString());
2414+
DCHECK(args[4]->IsString());
2415+
uint32_t trace_id = args[0].As<Uint32>()->Value();
2416+
uint32_t type = args[1].As<Uint32>()->Value();
2417+
Local<String> value_s1 = args[2].As<String>();
2418+
Local<String> value_s2 = args[3].As<String>();
2419+
Local<String> value_s3 = args[4].As<String>();
2420+
BindingData* data = FromJSObject<BindingData>(args.This());
2421+
const std::string val1 = *String::Utf8Value(isolate, value_s1);
2422+
const std::string val2 = *String::Utf8Value(isolate, value_s2);
2423+
const std::string val3 = *String::Utf8Value(isolate, value_s3);
2424+
PushSpanDataStringImpl3(data, trace_id, type, val1, val2, val3);
2425+
}
2426+
2427+
2428+
void BindingData::FastPushSpanDataString3(v8::Local<v8::Object> receiver,
2429+
uint32_t trace_id,
2430+
uint32_t type,
2431+
const FastOneByteString& val1,
2432+
const FastOneByteString& val2,
2433+
const FastOneByteString& val3) {
2434+
PushSpanDataStringImpl3(FromJSObject<BindingData>(receiver),
2435+
trace_id,
2436+
type,
2437+
std::string(val1.data, val1.length),
2438+
std::string(val2.data, val2.length),
2439+
std::string(val3.data, val3.length));
2440+
}
2441+
2442+
void BindingData::PushSpanDataStringImpl3(BindingData* data,
2443+
uint32_t trace_id,
2444+
uint32_t type,
2445+
const std::string& val1,
2446+
const std::string& val2,
2447+
const std::string& val3) {
2448+
Span::PropType prop_type = static_cast<Span::PropType>(type);
2449+
ASSERT_EQ(prop_type, Span::kSpanHttpReqUrl);
2450+
auto prop =
2451+
Span::createSpanProp<std::string>(prop_type, val1 + "//" + val2 + val3);
2452+
EnvInst* envinst = data->env()->envinst_.get();
2453+
EnvList::Inst()->GetTracer()->pushSpanData(
2454+
SpanItem{ trace_id, envinst->thread_id(), std::move(prop) });
23952455
}
23962456

23972457

@@ -3041,6 +3101,10 @@ v8::CFunction BindingData::fast_push_span_data_double_(
30413101
v8::CFunction::Make(FastPushSpanDataDouble));
30423102
v8::CFunction BindingData::fast_push_span_data_uint64_(
30433103
v8::CFunction::Make(FastPushSpanDataUint64));
3104+
v8::CFunction BindingData::fast_push_span_data_string_(
3105+
v8::CFunction::Make(FastPushSpanDataString));
3106+
v8::CFunction BindingData::fast_push_span_data_string3_(
3107+
v8::CFunction::Make(FastPushSpanDataString3));
30443108

30453109

30463110
void BindingData::Initialize(Local<Object> target,
@@ -3080,10 +3144,19 @@ void BindingData::Initialize(Local<Object> target,
30803144
"pushSpanDataUint64",
30813145
SlowPushSpanDataUint64,
30823146
&fast_push_span_data_uint64_);
3147+
SetFastMethod(context,
3148+
target,
3149+
"pushSpanDataString",
3150+
SlowPushSpanDataString,
3151+
&fast_push_span_data_string_);
3152+
SetFastMethod(context,
3153+
target,
3154+
"pushSpanDataString3",
3155+
SlowPushSpanDataString3,
3156+
&fast_push_span_data_string3_);
30833157

30843158
SetMethod(context, target, "agentId", AgentId);
30853159
SetMethod(context, target, "writeLog", WriteLog);
3086-
SetMethod(context, target, "pushSpanDataString", PushSpanDataString);
30873160
SetMethod(context, target, "getEnvMetrics", GetEnvMetrics);
30883161
SetMethod(context, target, "getProcessMetrics", GetProcessMetrics);
30893162
SetMethod(context, target, "getProcessInfo", GetProcessInfo);
@@ -3214,9 +3287,16 @@ void BindingData::RegisterExternalReferences(
32143287
registry->Register(FastPushSpanDataUint64);
32153288
registry->Register(fast_push_span_data_uint64_.GetTypeInfo());
32163289

3290+
registry->Register(SlowPushSpanDataString);
3291+
registry->Register(FastPushSpanDataString);
3292+
registry->Register(fast_push_span_data_string_.GetTypeInfo());
3293+
3294+
registry->Register(SlowPushSpanDataString3);
3295+
registry->Register(FastPushSpanDataString3);
3296+
registry->Register(fast_push_span_data_string3_.GetTypeInfo());
3297+
32173298
registry->Register(AgentId);
32183299
registry->Register(WriteLog);
3219-
registry->Register(PushSpanDataString);
32203300
registry->Register(GetEnvMetrics);
32213301
registry->Register(GetProcessMetrics);
32223302
registry->Register(GetProcessInfo);

src/nsolid/nsolid_bindings.h

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
#if defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS
55

66
#include "node_snapshotable.h"
7+
#include "v8-fast-api-calls.h"
78

89
namespace node {
910
namespace nsolid {
@@ -58,6 +59,31 @@ class BindingData : public SnapshotableObject {
5859
uint32_t type,
5960
uint64_t val);
6061

62+
static void SlowPushSpanDataString(
63+
const v8::FunctionCallbackInfo<v8::Value>& args);
64+
static void FastPushSpanDataString(v8::Local<v8::Object> receiver,
65+
uint32_t trace_id,
66+
uint32_t type,
67+
const v8::FastOneByteString& val);
68+
static void PushSpanDataStringImpl(BindingData* data,
69+
uint32_t trace_id,
70+
uint32_t type,
71+
const std::string& val);
72+
static void SlowPushSpanDataString3(
73+
const v8::FunctionCallbackInfo<v8::Value>& args);
74+
static void FastPushSpanDataString3(v8::Local<v8::Object> receiver,
75+
uint32_t trace_id,
76+
uint32_t type,
77+
const v8::FastOneByteString& val1,
78+
const v8::FastOneByteString& val2,
79+
const v8::FastOneByteString& val3);
80+
static void PushSpanDataStringImpl3(BindingData* data,
81+
uint32_t trace_id,
82+
uint32_t type,
83+
const std::string& val1,
84+
const std::string& val2,
85+
const std::string& val3);
86+
6187
static void Initialize(v8::Local<v8::Object> target,
6288
v8::Local<v8::Value> unused,
6389
v8::Local<v8::Context> context,
@@ -71,6 +97,8 @@ class BindingData : public SnapshotableObject {
7197
static v8::CFunction fast_push_server_bucket_;
7298
static v8::CFunction fast_push_span_data_double_;
7399
static v8::CFunction fast_push_span_data_uint64_;
100+
static v8::CFunction fast_push_span_data_string_;
101+
static v8::CFunction fast_push_span_data_string3_;
74102
};
75103

76104
} // namespace nsolid

src/nsolid/nsolid_trace.cc

Lines changed: 12 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -49,16 +49,19 @@ void Span::add_prop(const SpanPropBase& prop) {
4949
stor_.start = performance_process_start_timestamp + prop.val<double>();
5050
}
5151
break;
52-
case Span::kSpanOtelIds:
52+
case Span::kSpanTraceId:
5353
{
54-
auto res = utils::split(prop.val<std::string>(), ':', 3);
55-
size_t size = res.size();
56-
DCHECK(size == 2 || size == 3);
57-
stor_.trace_id = res[0];
58-
stor_.span_id = res[1];
59-
if (size == 3) {
60-
stor_.parent_id = res[2];
61-
}
54+
stor_.trace_id = prop.val<std::string>();
55+
}
56+
break;
57+
case Span::kSpanSpanId:
58+
{
59+
stor_.span_id = prop.val<std::string>();
60+
}
61+
break;
62+
case Span::kSpanParentSpanId:
63+
{
64+
stor_.parent_id = prop.val<std::string>();
6265
}
6366
break;
6467
case Span::kSpanEnd:

0 commit comments

Comments
 (0)