Skip to content

Commit 12d6d66

Browse files
authored
fix: guard against apm-clients encoding/truncation of trace objects throwing (#4359)
We have observed an exception from 'truncate.transaction()' twice, to my knowledge. I have been unable to reproduce it so far. A possible side-effect of client._encode throwing in the apm-client is that it effectively gets wedged ('corked()'). Refs: #1966
1 parent 4d8f0af commit 12d6d66

File tree

2 files changed

+68
-10
lines changed

2 files changed

+68
-10
lines changed

CHANGELOG.asciidoc

+5
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,11 @@ See the <<upgrade-to-v4>> guide.
4646
[float]
4747
===== Bug fixes
4848
49+
* Guard against a possible encoding error of tracing data in the APM client,
50+
before it is sent. It is *possible* this could wedge the APM client,
51+
resulting in the APM agent no longer sending tracing data.
52+
({pull}4359[#4359])
53+
4954
[float]
5055
===== Chores
5156

lib/apm-client/http-apm-client/index.js

+63-10
Original file line numberDiff line numberDiff line change
@@ -405,6 +405,15 @@ Client.prototype._resetEncodedMetadata = function () {
405405

406406
// This is the only code path that should set `_encodedMetadata`.
407407
this._encodedMetadata = this._encode({ metadata }, Client.encoding.METADATA);
408+
if (!this._encodedMetadata) {
409+
// The APM client cannot function without encoded metadata. Handling this
410+
// could be improved (e.g. log details and disable the APM agent). However,
411+
// this suffices for now as we have never observed a metadata encoding
412+
// failure.
413+
throw new Error(
414+
'could not encode metadata (trace-level logging will include details)',
415+
);
416+
}
408417
this._log.trace(
409418
{ _encodedMetadata: this._encodedMetadata },
410419
'_resetEncodedMetadata',
@@ -504,6 +513,9 @@ Client.prototype._write = function (obj, enc, cb) {
504513
} else {
505514
const t = process.hrtime();
506515
const chunk = this._encode(obj, enc);
516+
if (!chunk) {
517+
return;
518+
}
507519
this._numEventsEnqueued++;
508520
this._chopper.write(chunk, cb);
509521
this._log.trace(
@@ -579,12 +591,18 @@ Client.prototype._writeBatch = function (objs, cb) {
579591
const chunks = [];
580592
for (var i = 0; i < objs.length; i++) {
581593
const obj = objs[i];
582-
chunks.push(this._encode(obj.chunk, obj.encoding));
594+
const encoded = this._encode(obj.chunk, obj.encoding);
595+
if (encoded) {
596+
chunks.push(encoded);
597+
}
598+
}
599+
if (chunks.length === 0) {
600+
return;
583601
}
584602
const chunk = chunks.join('');
585603
const encodeTimeMs = deltaMs(t);
586604

587-
this._numEventsEnqueued += objs.length;
605+
this._numEventsEnqueued += chunks.length;
588606
this._chopper.write(chunk, cb);
589607
const fullTimeMs = deltaMs(t);
590608

@@ -601,7 +619,7 @@ Client.prototype._writeBatch = function (objs, cb) {
601619
{
602620
encodeTimeMs,
603621
fullTimeMs,
604-
numEvents: objs.length,
622+
numEvents: chunks.length,
605623
numBytes: chunk.length,
606624
},
607625
'_writeBatch',
@@ -687,24 +705,54 @@ Client.prototype._maybeUncork = function () {
687705
};
688706

689707
Client.prototype._encode = function (obj, enc) {
690-
const out = {};
708+
let thing;
709+
let truncFunc;
710+
let outAttr;
691711
switch (enc) {
692712
case Client.encoding.SPAN:
693-
out.span = truncate.span(obj.span, this._conf);
713+
thing = obj.span;
714+
truncFunc = truncate.span;
715+
outAttr = 'span';
694716
break;
695717
case Client.encoding.TRANSACTION:
696-
out.transaction = truncate.transaction(obj.transaction, this._conf);
718+
thing = obj.transaction;
719+
truncFunc = truncate.transaction;
720+
outAttr = 'transaction';
697721
break;
698722
case Client.encoding.METADATA:
699-
out.metadata = truncate.metadata(obj.metadata, this._conf);
723+
thing = obj.metadata;
724+
truncFunc = truncate.metadata;
725+
outAttr = 'metadata';
700726
break;
701727
case Client.encoding.ERROR:
702-
out.error = truncate.error(obj.error, this._conf);
728+
thing = obj.error;
729+
truncFunc = truncate.error;
730+
outAttr = 'error';
703731
break;
704732
case Client.encoding.METRICSET:
705-
out.metricset = truncate.metricset(obj.metricset, this._conf);
733+
thing = obj.metricset;
734+
truncFunc = truncate.metricset;
735+
outAttr = 'metricset';
706736
break;
707737
}
738+
739+
const out = {};
740+
try {
741+
out[outAttr] = truncFunc(thing, this._conf);
742+
} catch (err) {
743+
this._log.warn(
744+
{
745+
err,
746+
// Only log full problematic object at TRACE level to limit noise.
747+
thing: this._log.isLevelEnabled('trace') ? thing : '[REDACTED]',
748+
thing_id: thing?.id,
749+
thing_name: thing?.name,
750+
},
751+
`could not encode "${outAttr}" object`,
752+
);
753+
return null;
754+
}
755+
708756
return ndjson.serialize(out);
709757
};
710758

@@ -765,7 +813,6 @@ Client.prototype.lambdaRegisterTransaction = function (trans, awsRequestId) {
765813
{ awsRequestId, traceId: trans.trace_id, transId: trans.id },
766814
'lambdaRegisterTransaction start',
767815
);
768-
var out = this._encode({ transaction: trans }, Client.encoding.TRANSACTION);
769816

770817
const finish = (errOrErrMsg) => {
771818
const durationMs = performance.now() - startTime;
@@ -784,6 +831,12 @@ Client.prototype.lambdaRegisterTransaction = function (trans, awsRequestId) {
784831
resolve(); // always resolve, never reject
785832
};
786833

834+
var out = this._encode({ transaction: trans }, Client.encoding.TRANSACTION);
835+
if (!out) {
836+
finish('could not encode transaction');
837+
return;
838+
}
839+
787840
// Every `POST /register/transaction` request must set the
788841
// `x-elastic-aws-request-id` header. Instead of creating a new options obj
789842
// each time, we just modify in-place.

0 commit comments

Comments
 (0)