diff --git a/integration_tests/snapshots/logs/async-metrics_node12_with_plugin.log b/integration_tests/snapshots/logs/async-metrics_node12_with_plugin.log index 7fa80f02..3c595ef0 100644 --- a/integration_tests/snapshots/logs/async-metrics_node12_with_plugin.log +++ b/integration_tests/snapshots/logs/async-metrics_node12_with_plugin.log @@ -11,8 +11,8 @@ START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-plugin-dev-async-metrics_node12_with_plugin","resource:integration-plugin-dev-async-metrics_node12_with_plugin","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs12.x"],"v":1} {"e":XXXX,"m":"serverless.integration_test.records_processed","t":["tagkey:tagvalue","eventsource:SNS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["tagkey:tagvalue","eventsource:SNS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} -{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-async-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-async-metrics_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-async-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sns","function_trigger.event_source_arn":"arn:aws:sns:us-east-2:123456789012:sns-lambda"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed SNS request +{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-async-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-async-metrics_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-async-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sns","function_trigger.event_source_arn":"arn:aws:sns:us-east-2:123456789012:sns-lambda"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true @@ -22,8 +22,8 @@ START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"serverless.integration_test.records_processed","t":["tagkey:tagvalue","eventsource:SQS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} {"e":XXXX,"m":"serverless.integration_test.records_processed","t":["tagkey:tagvalue","eventsource:SQS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["tagkey:tagvalue","eventsource:SQS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} -{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-async-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-async-metrics_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-async-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sqs","function_trigger.event_source_arn":"arn:aws:sqs:us-east-2:123456789012:my-queue"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed SQS request +{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-async-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-async-metrics_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-async-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sqs","function_trigger.event_source_arn":"arn:aws:sqs:us-east-2:123456789012:my-queue"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true diff --git a/integration_tests/snapshots/logs/async-metrics_node14.log b/integration_tests/snapshots/logs/async-metrics_node14.log index 79a6bdc3..e7f466a2 100644 --- a/integration_tests/snapshots/logs/async-metrics_node14.log +++ b/integration_tests/snapshots/logs/async-metrics_node14.log @@ -7,10 +7,10 @@ REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1 XRAY TraceId: XXXX SegmentId: XXXX Sampled: true START RequestId: XXXX Version: $LATEST -XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed SNS request {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-dev-async-metrics_node14","resource:integration-dev-async-metrics_node14","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs14.x"],"v":1} {"e":XXXX,"m":"serverless.integration_test.records_processed","t":["tagkey:tagvalue","eventsource:SNS","dd_lambda_layer:datadog-nodev14.XX.X"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["tagkey:tagvalue","eventsource:SNS","dd_lambda_layer:datadog-nodev14.XX.X"],"v":1} +XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed SNS request END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true diff --git a/integration_tests/snapshots/logs/http-requests_node12_with_plugin.log b/integration_tests/snapshots/logs/http-requests_node12_with_plugin.log index 8765fc63..d68edaac 100644 --- a/integration_tests/snapshots/logs/http-requests_node12_with_plugin.log +++ b/integration_tests/snapshots/logs/http-requests_node12_with_plugin.log @@ -19,8 +19,8 @@ XRAY TraceId: XXXX SegmentId: XXXX Sampled: true START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-plugin-dev-http-requests_node12_with_plugin","resource:integration-plugin-dev-http-requests_node12_with_plugin","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs12.x"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["function:http-request","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} -{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"http.request","resource":"GET","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-http-requests_node12_with_plugin","span.kind":"client","http.method":"GET","http.url":"https://ip-ranges.datadoghq.com/","http.status_code":"200"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"integration-plugin-dev-http-requests_node12_with_plugin-http-client","type":"http"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"http.request","resource":"GET","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-http-requests_node12_with_plugin","span.kind":"client","http.method":"GET","http.url":"https://ip-ranges.datadoghq.eu/","http.status_code":"200"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"integration-plugin-dev-http-requests_node12_with_plugin-http-client","type":"http"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-http-requests_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-http-requests_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-http-requests_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sqs","function_trigger.event_source_arn":"arn:aws:sqs:us-east-2:123456789012:my-queue"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Snapshot test http requests successfully made to URLs: https://ip-ranges.datadoghq.com,https://ip-ranges.datadoghq.eu +{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"http.request","resource":"GET","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-http-requests_node12_with_plugin","span.kind":"client","http.method":"GET","http.url":"https://ip-ranges.datadoghq.com/","http.status_code":"200"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"integration-plugin-dev-http-requests_node12_with_plugin-http-client","type":"http"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"http.request","resource":"GET","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-http-requests_node12_with_plugin","span.kind":"client","http.method":"GET","http.url":"https://ip-ranges.datadoghq.eu/","http.status_code":"200"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"integration-plugin-dev-http-requests_node12_with_plugin-http-client","type":"http"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-http-requests_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-http-requests_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-http-requests_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sqs","function_trigger.event_source_arn":"arn:aws:sqs:us-east-2:123456789012:my-queue"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true diff --git a/integration_tests/snapshots/logs/http-requests_node14.log b/integration_tests/snapshots/logs/http-requests_node14.log index ccf43107..189cf111 100644 --- a/integration_tests/snapshots/logs/http-requests_node14.log +++ b/integration_tests/snapshots/logs/http-requests_node14.log @@ -22,8 +22,8 @@ START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-dev-http-requests_node14","resource:integration-dev-http-requests_node14","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs14.x"],"v":1} HTTP GET https://ip-ranges.datadoghq.com/ Headers: ["Accept:application/json, text/plain, */*","User-Agent:axios/0.21.1","x-datadog-parent-id:XXXX","x-datadog-sampling-priority:2","x-datadog-trace-id:XXXX"] HTTP GET https://ip-ranges.datadoghq.eu/ Headers: ["Accept:application/json, text/plain, */*","User-Agent:axios/0.21.1","x-datadog-parent-id:XXXX","x-datadog-sampling-priority:2","x-datadog-trace-id:XXXX"] -HTTP POST https://api.datadoghq.com/api/v1/distribution_points?api_key=XXXX Headers: ["content-type:application/json","x-datadog-parent-id:XXXX","x-datadog-sampling-priority:2","x-datadog-trace-id:XXXX"] XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Snapshot test http requests successfully made to URLs: https://ip-ranges.datadoghq.com,https://ip-ranges.datadoghq.eu +HTTP POST https://api.datadoghq.com/api/v1/distribution_points?api_key=XXXX Headers: ["content-type:application/json","x-datadog-parent-id:XXXX","x-datadog-sampling-priority:2","x-datadog-trace-id:XXXX"] END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true diff --git a/integration_tests/snapshots/logs/http-requests_node14_with_plugin.log b/integration_tests/snapshots/logs/http-requests_node14_with_plugin.log index d55535d0..318d9d7f 100644 --- a/integration_tests/snapshots/logs/http-requests_node14_with_plugin.log +++ b/integration_tests/snapshots/logs/http-requests_node14_with_plugin.log @@ -1,4 +1,3 @@ -XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO Snapshot test http requests successfully made to URLs: https://ip-ranges.datadoghq.com,https://ip-ranges.datadoghq.eu START RequestId: XXXX Version: $LATEST XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX ERROR {"status":"error","message":"datadog:handler not initialized"} XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO Snapshot test http requests successfully made to URLs: https://ip-ranges.datadoghq.com,https://ip-ranges.datadoghq.eu diff --git a/integration_tests/snapshots/logs/process-input-traced_node14.log b/integration_tests/snapshots/logs/process-input-traced_node14.log index 3abe99ca..0f3246a9 100644 --- a/integration_tests/snapshots/logs/process-input-traced_node14.log +++ b/integration_tests/snapshots/logs/process-input-traced_node14.log @@ -3,12 +3,12 @@ START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"serverless.integration_test.execution","t":["function:process-input-traced","dd_lambda_layer:datadog-nodev14.XX.X"],"v":1} {"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"getRecordIds","resource":"getRecordIds","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","language":"javascript"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"integration-dev-process-input-traced_node14"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"getAPIGatewayRequestId","resource":"getAPIGatewayRequestId","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","api_gateway_request_id":"41b45ea3-70b5-11e6-b7bd-69b5aaebc7d9","event_type":"APIGateway","language":"javascript"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"integration-dev-process-input-traced_node14"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-dev-process-input-traced_node14","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","cold_start":"true","function_arn":"XXXX_node14","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-dev-process-input-traced_node14","datadog_lambda":"XXXX","dd_trace":"XXXX","function_trigger.event_source":"api-gateway","function_trigger.event_source_arn":"arn:aws:apigateway:us-east-1::/restapis/wt6mne2s9k/stages/test","http.method":"GET","api_gateway_request_id":"41b45ea3-70b5-11e6-b7bd-69b5aaebc7d9","event_type":"APIGateway","http.status_code":"200"},"metrics":{"_sample_rate":1,"_dd.agent_psr":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} {"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"dns.lookup","resource":"0.0.0.0","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","span.kind":"client","dns.hostname":"0.0.0.0","dns.address":"XXXX"},"metrics":{"_sample_rate":1,"_dd.agent_psr":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"integration-dev-process-input-traced_node14-dns"}]]} +{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"dns.lookup","resource":"169.254.79.2","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","span.kind":"client","dns.hostname":"169.254.79.2","dns.address":"XXXX"},"metrics":{"_sample_rate":1,"_dd.agent_psr":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"integration-dev-process-input-traced_node14-dns"}]]} END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB Init Duration: XXXX ms XRAY TraceId: XXXX SegmentId: XXXX Sampled: true START RequestId: XXXX Version: $LATEST -{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"dns.lookup","resource":"169.254.79.2","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","span.kind":"client","dns.hostname":"169.254.79.2","dns.address":"XXXX"},"metrics":{"_sample_rate":1,"_dd.agent_psr":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"integration-dev-process-input-traced_node14-dns"}]]} {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-dev-process-input-traced_node14","resource:integration-dev-process-input-traced_node14","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs14.x"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["function:process-input-traced","dd_lambda_layer:datadog-nodev14.XX.X"],"v":1} {"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"getRecordIds","resource":"getRecordIds","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","record_event_type":"SNS","record_ids":"95df01b4-ee98-5cb9-9903-4c221d41eb5e","language":"javascript"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"integration-dev-process-input-traced_node14"},{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-dev-process-input-traced_node14","error":0,"meta":{"service":"integration-dev-process-input-traced_node14","cold_start":"false","function_arn":"XXXX_node14","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-dev-process-input-traced_node14","datadog_lambda":"XXXX","dd_trace":"XXXX","function_trigger.event_source":"sns","function_trigger.event_source_arn":"arn:aws:sns:us-east-2:123456789012:sns-lambda","event_type":"SNS"},"metrics":{"_sample_rate":1,"_dd.agent_psr":1,"_sampling_priority_v1":1},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} diff --git a/integration_tests/snapshots/logs/sync-metrics_node12_with_plugin.log b/integration_tests/snapshots/logs/sync-metrics_node12_with_plugin.log index fc0d74d7..2ce2f1b7 100644 --- a/integration_tests/snapshots/logs/sync-metrics_node12_with_plugin.log +++ b/integration_tests/snapshots/logs/sync-metrics_node12_with_plugin.log @@ -1,8 +1,8 @@ START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-plugin-dev-sync-metrics_node12_with_plugin","resource:integration-plugin-dev-sync-metrics_node12_with_plugin","cold_start:true","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs12.x"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["tagkey:tagvalue","eventsource:APIGateway","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} -XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed APIGateway request {"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-sync-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-sync-metrics_node12_with_plugin","cold_start":"true","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-sync-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"api-gateway","function_trigger.event_source_arn":"arn:aws:apigateway:us-east-1::/restapis/wt6mne2s9k/stages/test","http.method":"GET","http.status_code":"200"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} +XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed APIGateway request END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB Init Duration: XXXX ms XRAY TraceId: XXXX SegmentId: XXXX Sampled: true @@ -22,8 +22,8 @@ START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"serverless.integration_test.records_processed","t":["tagkey:tagvalue","eventsource:SQS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} {"e":XXXX,"m":"serverless.integration_test.records_processed","t":["tagkey:tagvalue","eventsource:SQS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} {"e":XXXX,"m":"serverless.integration_test.execution","t":["tagkey:tagvalue","eventsource:SQS","dd_lambda_layer:datadog-nodev12.XX.X"],"v":1} -{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-sync-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-sync-metrics_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-sync-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sqs","function_trigger.event_source_arn":"arn:aws:sqs:us-east-2:123456789012:my-queue"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX INFO [dd.trace_id=XXXX dd.span_id=XXXX] Processed SQS request +{"traces":[[{"trace_id":"XXXX","span_id":"XXXX","parent_id":"XXXX","name":"aws.lambda","resource":"integration-plugin-dev-sync-metrics_node12_with_plugin","error":0,"meta":{"_dd.origin":"lambda","service":"integration-plugin-dev-sync-metrics_node12_with_plugin","cold_start":"false","function_arn":"XXXX_node12_with_plugin","function_version":"$LATEST","request_id":"XXXX","resource_names":"integration-plugin-dev-sync-metrics_node12_with_plugin","datadog_lambda":"XXXX","dd_trace":"XXXX","_dd.parent_source":"xray","function_trigger.event_source":"sqs","function_trigger.event_source_arn":"arn:aws:sqs:us-east-2:123456789012:my-queue"},"metrics":{"_sample_rate":1,"_sampling_priority_v1":2},"start":XXXX,"duration":XXXX,"service":"aws.lambda","type":"serverless"}]]} END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true diff --git a/integration_tests/snapshots/logs/throw-error-traced_node12.log b/integration_tests/snapshots/logs/throw-error-traced_node12.log index 062904a2..e42d3dd4 100644 --- a/integration_tests/snapshots/logs/throw-error-traced_node12.log +++ b/integration_tests/snapshots/logs/throw-error-traced_node12.log @@ -8,8 +8,8 @@ XRAY TraceId: XXXX SegmentId: XXXX Sampled: true START RequestId: XXXX Version: $LATEST {"e":XXXX,"m":"aws.lambda.enhanced.invocations","t":["region:us-east-1","account_id:XXXX","functionname:integration-dev-throw-error-traced_node12","resource:integration-dev-throw-error-traced_node12","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs12.x"],"v":1} -{"e":XXXX,"m":"aws.lambda.enhanced.errors","t":["region:us-east-1","account_id:XXXX","functionname:integration-dev-throw-error-traced_node12","resource:integration-dev-throw-error-traced_node12","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs12.x"],"v":1} XXXX-XX-XX XX:XX:XX.XXX XXXX-XXXX-XXXX-XXXX-XXXX ERROR [dd.trace_id=XXXX dd.span_id=XXXX] Invoke Error {"errorType":"Error","errorMessage":"Hello","stack":["Error: Hello"," at handle (/var/task/throw-error-traced.js:4:11)"," at /var/task/node_modules/datadog-lambda-js/dist/utils/handler.js:150:25"," at /var/task/node_modules/datadog-lambda-js/dist/index.js:167:62"," at step (/var/task/node_modules/datadog-lambda-js/dist/index.js:44:23)"," at Object.next (/var/task/node_modules/datadog-lambda-js/dist/index.js:25:53)"," at /var/task/node_modules/datadog-lambda-js/dist/index.js:19:71"," at new Promise ()"," at __awaiter (/var/task/node_modules/datadog-lambda-js/dist/index.js:15:12)"," at /var/task/node_modules/datadog-lambda-js/dist/index.js:161:108"," at /var/task/node_modules/datadog-lambda-js/dist/index.js:186:31"]} +{"e":XXXX,"m":"aws.lambda.enhanced.errors","t":["region:us-east-1","account_id:XXXX","functionname:integration-dev-throw-error-traced_node12","resource:integration-dev-throw-error-traced_node12","cold_start:false","memorysize:1024","datadog_lambda:vX.X.X","runtime:nodejs12.x"],"v":1} END RequestId: XXXX REPORT RequestId: XXXX Duration: XXXX ms Billed Duration: XXXX ms Memory Size: 1024 MB Max Memory Used: XXXX MB XRAY TraceId: XXXX SegmentId: XXXX Sampled: true diff --git a/package.json b/package.json index 5710527e..8a9f95a9 100644 --- a/package.json +++ b/package.json @@ -25,7 +25,7 @@ "@types/node": "^14.14.25", "@types/promise-retry": "^1.1.3", "@types/shimmer": "^1.0.1", - "dd-trace": "0.30.6", + "dd-trace": "0.31.0", "jest": "^26.6.3", "mock-fs": "4.13.0", "nock": "13.0.7", diff --git a/src/handler.ts b/src/handler.ts index 2de2c421..a6917aaf 100644 --- a/src/handler.ts +++ b/src/handler.ts @@ -1,12 +1,13 @@ import { datadog, datadogHandlerEnvVar, lambdaTaskRootEnvVar, traceExtractorEnvVar, getEnvValue } from "./index"; import { TraceExtractor } from "./trace"; -import { logError } from "./utils"; +import { logDebug, logError } from "./utils"; // We reuse the function loading logic already inside the lambda runtime. // tslint:disable-next-line:no-var-requires const { load } = require("/var/runtime/UserFunction") as any; if (process.env.DD_TRACE_DISABLED_PLUGINS === undefined) { process.env.DD_TRACE_DISABLED_PLUGINS = "fs"; + logDebug("disabled the dd-trace plugin 'fs'"); } if (getEnvValue("DD_TRACE_ENABLED", "true").toLowerCase() === "true") { @@ -16,6 +17,7 @@ if (getEnvValue("DD_TRACE_ENABLED", "true").toLowerCase() === "true") { "_dd.origin": "lambda", }, }); + logDebug("automatically initialized dd-trace"); } const taskRootEnv = getEnvValue(lambdaTaskRootEnvVar, ""); @@ -26,8 +28,9 @@ let traceExtractor; if (extractorEnv) { try { traceExtractor = load(taskRootEnv, extractorEnv) as TraceExtractor; + logDebug("loaded custom trace context extractor", { extractorEnv }); } catch (error) { - logError("an error occured while loading the extractor", error); + logError("an error occurred while loading the custom trace context extractor", { error, extractorEnv }); } } diff --git a/src/trace/context.ts b/src/trace/context.ts index bf1bc966..f8438ec8 100644 --- a/src/trace/context.ts +++ b/src/trace/context.ts @@ -57,8 +57,9 @@ export function extractTraceContext( if (extractor) { try { trace = extractor(event, context); + logDebug(`extracted trace context from the custom extractor`, { trace }); } catch (error) { - logError("extractor function failed", { error }); + logError("custom extractor function failed", { error }); } } @@ -78,12 +79,14 @@ export function extractTraceContext( logError("couldn't add step function metadata to xray", { innerError: error }); } } + if (trace !== undefined) { try { addTraceContextToXray(trace); + logDebug(`added trace context to xray metadata`, { trace }); } catch (error) { // This might fail if running in an environment where xray isn't set up, (like for local development). - logError("couldn't add metadata to xray", { innerError: error }); + logError("couldn't add trace context to xray metadata", { innerError: error }); } return trace; } @@ -198,12 +201,14 @@ export function readTraceFromSQSEvent(event: SQSEvent): TraceContext | undefined } const sampleMode = parseInt(sampledHeader, 10); - return { + const trace = { parentID, sampleMode, source: Source.Event, traceID, }; + logDebug(`extracted trace context from sqs event`, { trace, event }); + return trace; } catch (err) { logError("Error parsing SQS message trace data", err); return; @@ -238,12 +243,14 @@ export function readTraceFromLambdaContext(context: any): TraceContext | undefin } const sampleMode = parseInt(sampledHeader, 10); - return { + const trace = { parentID, sampleMode, source: Source.Event, traceID, }; + logDebug(`extracted trace context from lambda context`, { trace, context }); + return trace; } export function readTraceFromHTTPEvent(event: any): TraceContext | undefined { @@ -268,12 +275,15 @@ export function readTraceFromHTTPEvent(event: any): TraceContext | undefined { } const sampleMode = parseInt(sampledHeader, 10); - return { + const trace = { parentID, sampleMode, source: Source.Event, traceID, }; + + logDebug(`extracted trace context from http event`, { trace, event }); + return trace; } export function readTraceFromEvent(event: any): TraceContext | undefined { @@ -316,12 +326,14 @@ export function readTraceContextFromXray(): TraceContext | undefined { } const sampleMode = convertToSampleMode(parseInt(context.xraySampled, 10)); - return { + const trace = { parentID, sampleMode, source: Source.Xray, traceID, }; + logDebug(`extracted trace context from xray context`, { trace, header }); + return trace; } export function parseXrayTraceContextHeader(header: string) { diff --git a/src/trace/listener.spec.ts b/src/trace/listener.spec.ts index 647dff5f..3c7111b2 100644 --- a/src/trace/listener.spec.ts +++ b/src/trace/listener.spec.ts @@ -35,7 +35,7 @@ jest.mock("./trace-context-service", () => { get traceSource() { return mockTraceSource; } - get currentTraceHeaders() { + get rootTraceHeaders() { return mockTraceHeaders; } } diff --git a/src/trace/listener.ts b/src/trace/listener.ts index 732f879e..96a4c242 100644 --- a/src/trace/listener.ts +++ b/src/trace/listener.ts @@ -97,14 +97,15 @@ export class TraceListener { } public onWrap any>(func: T): T { - const rootTraceContext = this.currentTraceHeaders; - let spanContext: SpanContext | null = null; - + // The aws.lambda span needs to have a parented to the Datadog trace context from the + // incoming event if available or the X-Ray trace context if hybrid tracing is enabled + let parentSpanContext: SpanContext | null = null; if (this.contextService.traceSource === Source.Event || this.config.mergeDatadogXrayTraces) { - spanContext = this.tracerWrapper.extract(rootTraceContext); - logDebug("Attempting to find parent for datadog trace trace"); + const rootTraceHeaders = this.contextService.rootTraceHeaders; + parentSpanContext = this.tracerWrapper.extract(rootTraceHeaders); + logDebug("Attempting to find parent for the aws.lambda span"); } else { - logDebug("Didn't attempt to find parent for datadog trace", { + logDebug("Didn't attempt to find parent for aws.lambda span", { mergeDatadogXrayTraces: this.config.mergeDatadogXrayTraces, traceSource: this.contextService.traceSource, }); @@ -112,7 +113,7 @@ export class TraceListener { const options: TraceOptions = {}; if (this.context) { - logDebug("Applying lambda context to datadog traces"); + logDebug("Creating the aws.lambda span"); const functionArn = (this.context.invokedFunctionArn ?? "").toLowerCase(); const tk = functionArn.split(":"); options.tags = { @@ -135,15 +136,15 @@ export class TraceListener { } } if (this.stepFunctionContext) { - logDebug("Applying step function context to datadog traces"); + logDebug("Applying step function context to the aws.lambda span"); options.tags = { ...options.tags, ...this.stepFunctionContext, }; } - if (spanContext !== null) { - options.childOf = spanContext; + if (parentSpanContext !== null) { + options.childOf = parentSpanContext; } options.type = "serverless"; options.service = "aws.lambda"; diff --git a/src/trace/trace-context-service.ts b/src/trace/trace-context-service.ts index b31c30dd..ab0f8d6b 100644 --- a/src/trace/trace-context-service.ts +++ b/src/trace/trace-context-service.ts @@ -33,19 +33,22 @@ export class TraceContextService { return; } const traceContext = { ...this.rootTraceContext }; + + // Update the parent id to the active datadog span if available const datadogContext = this.tracerWrapper.traceContext(); if (datadogContext) { logDebug(`set trace context from dd-trace with parent ${datadogContext.parentID}`); return datadogContext; } + // Update the parent id to the active X-Ray subsegment if available const xraySegment = this.getXraySegment(); if (xraySegment === undefined) { logDebug("couldn't retrieve segment from xray"); } else { const value = convertToAPMParentID(xraySegment.id); if (value !== undefined) { - logDebug(`set trace context from xray with parent ${value} from segment`); + logDebug(`set trace context from xray with parent ${value} from segment`, { xraySegment }); traceContext.parentID = value; } } @@ -53,14 +56,30 @@ export class TraceContextService { return traceContext; } + // Get the current trace headers to be propagated to the downstream calls, + // The parent id always points to the current active span. get currentTraceHeaders(): Partial { - if (this.currentTraceContext === undefined) { + const traceContext = this.currentTraceContext; + if (traceContext === undefined) { + return {}; + } + return { + [traceIDHeader]: traceContext.traceID, + [parentIDHeader]: traceContext.parentID, + [samplingPriorityHeader]: traceContext.sampleMode.toString(10), + }; + } + + // Get the trace headers from the root trace context. + get rootTraceHeaders(): Partial { + const rootTraceContext = this.rootTraceContext; + if (rootTraceContext === undefined) { return {}; } return { - [traceIDHeader]: this.currentTraceContext.traceID, - [parentIDHeader]: this.currentTraceContext.parentID, - [samplingPriorityHeader]: this.currentTraceContext.sampleMode.toString(10), + [traceIDHeader]: rootTraceContext.traceID, + [parentIDHeader]: rootTraceContext.parentID, + [samplingPriorityHeader]: rootTraceContext.sampleMode.toString(10), }; } @@ -68,6 +87,8 @@ export class TraceContextService { return this.rootTraceContext !== undefined ? this.rootTraceContext.source : undefined; } + // Get the current X-Ray (sub)segment. Note, this always return a + // (sub)segment even if when X-Ray active tracing is not enabled. private getXraySegment(): Segment | undefined { // Newer versions of X-Ray core sdk will either throw // an exception or log a noisy output message when segment is empty. diff --git a/yarn.lock b/yarn.lock index d2e67b41..daa4e6ff 100644 --- a/yarn.lock +++ b/yarn.lock @@ -1326,10 +1326,10 @@ data-urls@^2.0.0: whatwg-mimetype "^2.3.0" whatwg-url "^8.0.0" -dd-trace@0.30.6: - version "0.30.6" - resolved "https://registry.yarnpkg.com/dd-trace/-/dd-trace-0.30.6.tgz#a151df42f618b46ff4a54e832608442763c380de" - integrity sha512-VLOHamLQzSJ2Xlc+2CISZle7IV8Og9tLKG0NfVgJCr9NDsuakNugv0NQXJNKAQLRiWbR4vzNb2otx0b5tYBeDQ== +dd-trace@0.31.0: + version "0.31.0" + resolved "https://registry.yarnpkg.com/dd-trace/-/dd-trace-0.31.0.tgz#5193b51b7d8ba1ea3aba17f5132703a2dae28f35" + integrity sha512-/a95KtcmOq6lQxYpdbgjDuQOuDwlHKtPW2r5RywSmibHkZVPeRsHjmS4YZB7o9xVNZijJr++QcvXDpJ0b2ITmQ== dependencies: "@types/node" "^10.12.18" axios "^0.21.1"