parent.addNewSubsegmentWithoutSampling is not a function

[piotrjak]

Overview

• node v16.20.0
• aws-xray-sdk-node v3.4.1
• the error started occurring after we started to use AWSXRay.captureHTTPsGlobal(require('https'));
• this is where it throws an error -> var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/aws-xray-sdk-core/dist/lib/patchers/http_p.js:103:33)

      if (parent.notTraced) {
          subsegment = parent.addNewSubsegmentWithoutSampling(hostname);
      }

• addNewSubsegmentWithoutSampling is undefined (I set a debugger just before this function is invoked)

in the Debug Console

parent.addNewSubsegmentWithoutSampling
undefined

this method doesn't exist

parent
{"trace_id":"1-00000000-000000000000000000000000","id":"00000000","start_time":1680704786.183,"name":"facade","in_progress":false,"counter":1,"service":{"runtime":"node","runtime_version":"v16.20.0","version":"unknown","name":"unknown"},"aws":{"xray":{"sdk":"X-Ray for Node.js","sdk_version":"3.3.7","package":"aws-xray-sdk-core"}},"notTraced":true,"facade":true,"subsegments":[]}
addAnnotation:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addError:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addErrorFlag:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addFaultFlag:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addIncomingRequestData:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addMetadata:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addPluginData:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
addThrottleFlag:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
aws:
{xray: {…}}
close:
ƒ facade() {\n                    return;\n                }
counter:
1
decrementCounter:
ƒ facade() {\n                    return;\n                }
facade:
true
flush:
ƒ facade() {\n                    return;\n                }
format:
ƒ facade() {\n                    return;\n                }
id:
'00000000'
in_progress:
false
incrementCounter:
ƒ facade() {\n                    return;\n                }
init:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
isClosed:
ƒ () {\n        return true;\n    }
name:
'facade'
notTraced:
true
reset:
ƒ reset() {\n        this.trace_id = TraceID.Invalid().toString();\n        this.id = '00000000';\n        delete this.subsegments;\n        this.notTraced = true;\n    }
resolveLambdaTraceData:
ƒ resolveLambdaTraceData() {\n        var xAmznLambda = process.env._X_AMZN_TRACE_ID;\n        if (xAmznLambda) {\n            // This check resets the trace data whenever a new trace header is read to not leak data between invocations\n            if (xAmznLambda != xAmznTraceIdPrev) {\n                this.reset();\n                if (LambdaUtils.populateTraceData(segment, xAmznLambda)) {\n                    xAmznTraceIdPrev = xAmznLambda;\n                }\n            }\n        }\n        else {\n            this.reset();\n            contextUtils.contextMissingStrategy.contextMissing('Missing AWS Lambda trace data for X-Ray. ' +\n                'Ensure Active Tracing is enabled and no subsegments are created outside the function handler.');\n        }\n    }
service:
{runtime: 'node', runtime_version: 'v16.20.0', version: 'unknown', name: 'unknown'}
setMatchedSamplingRule:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
setSDKData:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
setServiceData:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
setUser:
ƒ facade() {\n                        logger.getLogger().warn('Function "' + func + '" cannot be called on an AWS Lambda segment. Please use a subsegment to record data.');\n                        return;\n                    }
start_time:
1680704786.183
subsegments:
(0) []
trace_id:
'1-00000000-000000000000000000000000'
[[Prototype]]:
Object
addAnnotation:
ƒ addAnnotation(key, value) {\n    if (typeof value !== 'boolean' && typeof value !== 'string' && !isFinite(value)) {\n        logger.getLogger().error('Failed to add annotation key: ' + key + ' value: ' + value + ' to subsegment ' +\n            this.name + '. Value must be of type string, number or boolean.');\n        return;\n    }\n    if (typeof key !== 'string') {\n        logger.getLogger().error('Failed to add annotation key: ' + key + ' value: ' + value + ' to subsegment ' +\n            this.name + '. Key must be of type string.');\n        return;\n    }\n    if (this.annotations === undefined) {\n        this.annotations = {};\n    }\n    this.annotations[key] = value;\n}
addError:
ƒ addError(err, remote) {\n    if (err == null || typeof err !== 'object' && typeof (err) !== 'string') {\n        logger.getLogger().error('Failed to add error:' + err + ' to subsegment "' + this.name +\n            '".  Not an object or string literal.');\n        return;\n    }\n    this.addFaultFlag();\n    if (this.exception) {\n        if (err === this.exception.ex) {\n            this.cause = { id: this.exception.cause };\n            delete this.exception;\n            return;\n        }\n        delete this.exception;\n    }\n    if (this.cause === undefined) {\n        this.cause = {\n            working_directory: process.cwd(),\n            exceptions: []\n        };\n    }\n    this.cause.exceptions.push(new CapturedException(err, remote));\n}
addErrorFlag:
ƒ addErrorFlag() {\n    this.error = true;\n}
addFaultFlag:
ƒ addFaultFlag() {\n    this.fault = true;\n}
addIncomingRequestData:
ƒ addIncomingRequestData(data) {\n    this.http = data;\n}
addMetadata:
ƒ (key, value, namespace) {\n    if (typeof key !== 'string') {\n        logger.getLogger().error('Failed to add metadata key: ' + key + ' value: ' + value + ' to segment ' +\n            this.name + '. Key must be of type string.');\n        return;\n    }\n    if (namespace && typeof namespace !== 'string') {\n        logger.getLogger().error('Failed to add metadata key: ' + key + ' value: ' + value + ' to segment ' +\n            this.name + '. Namespace must be of type string.');\n        return;\n    }\n    var ns = namespace || 'default';\n    if (!this.metadata) {\n        this.metadata = {};\n    }\n    if (!this.metadata[ns]) {\n        this.metadata[ns] = {};\n    }\n    if (ns !== '__proto__') {\n        this.metadata[ns][key] = value !== null && value !== undefined ? value : '';\n    }\n}
addNewSubsegment:
ƒ addNewSubsegment(name) {\n    var subsegment = new Subsegment(name);\n    this.addSubsegment(subsegment);\n    return subsegment;\n}
addPluginData:
ƒ addPluginData(data) {\n    if (this.aws === undefined) {\n        this.aws = {};\n    }\n    Object.assign(this.aws, data);\n}
addSubsegment:
ƒ addSubsegment(subsegment) {\n    if (!(subsegment instanceof Subsegment)) {\n        throw new Error('Cannot add subsegment: ' + subsegment + '. Not a subsegment.');\n    }\n    if (this.subsegments === undefined) {\n        this.subsegments = [];\n    }\n    subsegment.segment = this;\n    subsegment.parent = this;\n    this.subsegments.push(subsegment);\n    if (!subsegment.end_time) {\n        this.incrementCounter(subsegment.counter);\n    }\n}
addThrottleFlag:
ƒ addThrottleFlag() {\n    this.throttle = true;\n}
close:
ƒ (err, remote) {\n    if (!this.end_time) {\n        this.end_time = SegmentUtils.getCurrentTime();\n    }\n    if (err !== undefined) {\n        this.addError(err, remote);\n    }\n    delete this.in_progress;\n    delete this.exception;\n    if (this.counter <= 0) {\n        this.flush();\n    }\n}
decrementCounter:
ƒ decrementCounter() {\n    this.counter--;\n    if (this.counter <= 0 && this.isClosed()) {\n        this.flush();\n    }\n}
flush:
ƒ flush() {\n    if (this.notTraced !== true) {\n        delete this.exception;\n        var thisCopy = Utils.objectWithoutProperties(this, ['counter', 'notTraced'], true);\n        SegmentEmitter.send(thisCopy);\n    }\n}
format:
ƒ format() {\n    var ignore = ['segment', 'parent', 'counter'];\n    if (this.subsegments == null || this.subsegments.length === 0) {\n        ignore.push('subsegments');\n    }\n    var thisCopy = Utils.objectWithoutProperties(this, ignore, false);\n    return JSON.stringify(thisCopy);\n}
incrementCounter:
ƒ incrementCounter(additional) {\n    this.counter = additional ? this.counter + additional + 1 : this.counter + 1;\n    if (this.counter > SegmentUtils.streamingThreshold && this.subsegments && this.subsegments.length > 0) {\n        var open = [];\n        this.subsegments.forEach(function (child) {\n            if (!child.streamSubsegments()) {\n                open.push(child);\n            }\n        });\n        this.subsegments = open;\n    }\n}
init:
ƒ init(name, rootId, parentId)
isClosed:
ƒ isClosed() {\n    return !this.in_progress;\n}
removeSubsegment:
ƒ removeSubsegment(subsegment) {\n    if (!(subsegment instanceof Subsegment)) {\n        throw new Error('Failed to remove subsegment:' + subsegment + ' from subsegment "' + this.name +\n            '".  Not a subsegment.');\n    }\n    if (this.subsegments !== undefined) {\n        var index = this.subsegments.indexOf(subsegment);\n        if (index >= 0) {\n            this.subsegments.splice(index, 1);\n        }\n    }\n}
setMatchedSamplingRule:
ƒ setMatchedSamplingRule(ruleName) {\n    if (this.aws) {\n        this.aws = JSON.parse(JSON.stringify(this.aws));\n    }\n    if (this.aws && this.aws['xray']) {\n        this.aws.xray['rule_name'] = ruleName;\n    }\n    else {\n        this.aws = { xray: { 'rule_name': ruleName } };\n    }\n}
setSDKData:
ƒ setSDKData(data) {\n    if (!data) {\n        logger.getLogger().error('Add SDK data: ' + data + ' failed.' +\n            'Must not be empty.');\n        return;\n    }\n    if (!this.aws) {\n        this.aws = {};\n    }\n    this.aws.xray = data;\n}
setServiceData:
ƒ setServiceData(data) {\n    if (!data) {\n        logger.getLogger().error('Add service data: ' + data + ' failed.' +\n            'Must not be empty.');\n        return;\n    }\n    this.service = data;\n}
setUser:
ƒ (user) {\n    if (typeof user !== 'string') {\n        logger.getLogger().error('Set user: ' + user + ' failed. User IDs must be of type string.');\n    }\n    this.user = user;\n}
toString:
ƒ toString() {\n    return JSON.stringify(this);\n}
constructor:
ƒ Segment(name, rootId, parentId) {\n    this.init(name, rootId, parentId);\n}
[[Prototype]]:
Object

Why does it say that it's using sdk-version 3.3.7 though? may it be a module caching issue?

Stack

TypeError: parent.addNewSubsegmentWithoutSampling is not a function
    at captureOutgoingHTTPs (/var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/aws-xray-sdk-core/dist/lib/patchers/http_p.js:103:33)
    at Object.captureHTTPsRequest (/var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/aws-xray-sdk-core/dist/lib/patchers/http_p.js:173:16)
    at Object.wrappedMethod [as request] (/var/task/node_modules/@sentry/node/dist/integrations/http.js:95:18)
    at Request.request (/var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/superagent/lib/node/index.js:763:22)
    at Request.end (/var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/superagent/lib/node/index.js:919:8)
    at /var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/superagent/lib/request-base.js:266:12
    at new Promise (<anonymous>)
    at RequestBase.then (/var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/superagent/lib/request-base.js:250:31)

[piotrjak]

tl;dr this was the error

TypeError: parent.addNewSubsegmentWithoutSampling is not a function
    at captureOutgoingHTTPs (/var/task/node_modules/@lifeworks/http-client-with-tracing/node_modules/aws-xray-sdk-core/dist/lib/patchers/http_p.js:103:33)

I saw that we were using aws-xray-sdk-core in both http-client-with-tracing and aws-sdk-helpers they were both using different versions of this package -> 3.4.1 and 3.3.7 3.3.7 was at node_modules/aws-xray-sdk-core 3.4.1 was at node_modules/@lifeworks/http-client-with-tracing/node_modules/aws-xray-sdk-core

http-client-with-tracing loaded aws-xray-sdk-core first (as it was required earlier) and then aws-sdk-helpers loaded. but it was aws-sdk-helpers that first sent a request (which was intercepted by aws-xray-sdk-core). captureOutgoingHTTPs from http-client-with-tracing so it looks like it used the cached module (?)

it sent the request (SecretsManager.getSecretValue), but then http-client-with-tracing sent an HTTP request. aws-xray-sdk-core got an Xray segment from CLS ("node's local storage" -> like a global object that lives between requests) that is later used. but looks like this segment came from this other version of aws-xray-sdk-core

(on the screenshot parent is the object from getSegment)

and then the method from this shared object was used to call a method on it from library 3.4.1 that was unavailable

I found that this Segment is set in node_modules/aws-xray-sdk-core/dist/lib/env/aws_lambda.js:34 so it's the aws-xray-sdk-core from aws-sdk-helpers - that's called by init (node_modules/aws-xray-sdk-core/dist/lib/aws-xray.js:303), but somehow it later calls captureOutgoingHTTPs from aws-xray-sdk-core from http-client-with-tracing

this init file (4th screenshot) was run in the process of require (IIFE function) when the module was trying to be loaded. so I assume that even though the module was cached, this module still invoked this IIFE function which set the segment...)

TL;DR anyway, THE FIX was to update our helper packages so it uses only one version of aws-xray-sdk-core so the packages sits directly in node_modules/aws-xray-sdk-core .

[willarmiros]

Thanks @piotrjak for the writeup, sorry for not responding earlier. I believe this is a dupe of #544, and since you've resolved it I'll close this issue.