Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AWS SAM & AWS Lambda: pg spans not reported #13975

Closed
3 tasks done
ffraenz opened this issue Oct 14, 2024 · 8 comments
Closed
3 tasks done

AWS SAM & AWS Lambda: pg spans not reported #13975

ffraenz opened this issue Oct 14, 2024 · 8 comments
Labels
Package: aws-serverless Issues related to the Sentry AWS Serverless SDK

Comments

@ffraenz
Copy link

ffraenz commented Oct 14, 2024

Is there an existing issue for this?

How do you use Sentry?

Sentry Saas (sentry.io)

Which SDK are you using?

@sentry/aws-serverless

SDK Version

8.34.0

Framework Version

SAM CLI 1.125.0, pg 8.13.0, Drizzle ORM 0.34.1

Link to Sentry event

https://wierk.sentry.io/performance/trace/fd08bbde979368bd0e7e26c950fcdd92/?node=ms-6ae4ec7ba851d454&node=txn-dc57263b08454d93b3a3001bda12236e&pageEnd&pageStart&project=4508123298463824&source=traces&statsPeriod=24h&timestamp=1728945399.927

Reproduction Example/SDK Setup

I'd like to configure error reporting and profiling via @sentry/aws-serverless for a project that builds on the AWS SAM framework. AWS SAM offers tooling to build and deploy TypeScript source code to a Node.js AWS Lambda function via CloudFormation. The project uses Drizzle ORM and pg to interact with a database.

I've created a repository containing a minimal reproducible example: https://github.com/ffraenz/aws-sam-ts-pg-sentry.

Steps to Reproduce

Configure, build, and deploy the minimal reproducible example above on AWS and trigger it by clicking "Test" on the AWS Lambda UI in AWS Console. Results show up in the Sentry UI.

Expected Result

The function runs successfully. A Sentry transaction gets reported containing a trace with spans for two HTTP events and two Postgres queries executed via Drizzle.js and pg.

Actual Result

The function runs successfully. A Sentry transaction gets reported containing a trace with spans for two HTTP events but without any spans for pg queries. The missing span explicitly shows as "Missing instrumentation" in the UI. The trace shown in the following screenshot is linked above.

Image

For reference, this is the Sentry.init call from the repository mentioned above:

import * as Sentry from '@sentry/aws-serverless';
import { nodeProfilingIntegration } from '@sentry/profiling-node';

Sentry.init({
    dsn: process.env.SENTRY_DSN,
    integrations: [nodeProfilingIntegration(), Sentry.postgresIntegration()],
    tracesSampleRate: 1.0,
    profilesSampleRate: 1.0,
    debug: true,
});
AWS Lambda logs from AWS CloudWatch
INIT_START Runtime Version: nodejs:20.v39	Runtime Version ARN: arn:aws:lambda:eu-central-1::runtime:83d84646b3540dd38341195452110b2178a7231400ce6bc20c6179e5b297ae04
--
Sentry Logger [log]: Initializing Sentry: process: 2, thread: main.
Sentry Logger [log]: Integration installed: InboundFilters
Sentry Logger [log]: Integration installed: FunctionToString
Sentry Logger [log]: Integration installed: LinkedErrors
Sentry Logger [log]: Integration installed: RequestData
Sentry Logger [log]: Integration installed: Console
Sentry Logger [log]: Integration installed: Http
Sentry Logger [log]: Integration installed: NodeFetch
Sentry Logger [log]: Integration installed: OnUncaughtException
Sentry Logger [log]: Integration installed: OnUnhandledRejection
Sentry Logger [log]: Integration installed: ContextLines
Sentry Logger [log]: Integration installed: LocalVariablesAsync
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: Modules
Sentry Logger [log]: Integration installed: Aws
Sentry Logger [log]: Integration installed: AwsLambda
Sentry Logger [log]: [Profiling] Profiling integration setup.
Sentry Logger [log]: [Profiling] Span profiler mode enabled.
Sentry Logger [log]: Integration installed: ProfilingIntegration
Sentry Logger [log]: Integration installed: Postgres
Sentry Logger [log]: Running in CommonJS mode.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [warn]: Failed extracting version /var/task
Sentry Logger [debug]: @opentelemetry/instrumentation-aws-lambda Applying instrumentation patch for nodejs module file on require hook {
module: '/var/task/app.js',
version: undefined,
fileName: 'app',
baseDir: '/var/task'
}
Sentry Logger [debug]: patch handler function
START RequestId: 5b6a8284-c83c-4614-a4cf-e95a8a38123e Version: $LATEST
Sentry Logger [log]: [Tracing] Starting sampled root span
op: < unknown op >
name: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
ID: 434e5358e922b78b
2024-10-14T22:36:34.294Z	5b6a8284-c83c-4614-a4cf-e95a8a38123e	INFO	Batch 0
Sentry Logger [log]: [Profiling] started profiling transaction: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
Sentry Logger [log]: [Tracing] Starting sampled root span
op: function.aws.lambda
name: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
ID: 2627aa12341d8ca8
Sentry Logger [log]: [Profiling] started profiling transaction: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for GET: true
Sentry Logger [log]: [Tracing] Starting sampled span
op: < unknown op >
name: GET
ID: 6ae4ec7ba851d454
parent ID: 2627aa12341d8ca8
root ID: 2627aa12341d8ca8
root op: function.aws.lambda
root description: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "GET" with ID 6ae4ec7ba851d454
Sentry Logger [log]: SpanExporter has 1 unsent spans remaining
2024-10-14T22:36:36.176Z	5b6a8284-c83c-4614-a4cf-e95a8a38123e	INFO	Query: insert into "numbers" ("id", "number", "createdAt", "updatedAt") values (default, $1, default, default), (default, $2, default, default), (default, $3, default, default), (default, $4, default, default), (default, $5, default, default), (default, $6, default, default), (default, $7, default, default), (default, $8, default, default), (default, $9, default, default), (default, $10, default, default), (default, $11, default, default), (default, $12, default, default), (default, $13, default, default), (default, $14, default, default), (default, $15, default, default), (default, $16, default, default), (default, $17, default, default), (default, $18, default, default), (default, $19, default, default), (default, $20, default, default), (default, $21, default, default), (default, $22, default, default), (default, $23, default, default), (default, $24, default, default), (default, $25, default, default), (default, $26, default, default), (default, $27, default, default), (default, $28, default, default), (default, $29, default, default), (default, $30, default, default), (default, $31, default, default), (default, $32, default, default), (default, $33, default, default), (default, $34, default, default), (default, $35, default, default), (default, $36, default, default), (default, $37, default, default), (default, $38, default, default), (default, $39, default, default), (default, $40, default, default), (default, $41, default, default), (default, $42, default, default), (default, $43, default, default), (default, $44, default, default), (default, $45, default, default), (default, $46, default, default), (default, $47, default, default), (default, $48, default, default), (default, $49, default, default), (default, $50, default, default), (default, $51, default, default), (default, $52, default, default), (default, $53, default, default), (default, $54, default, default), (default, $55, default, default), (default, $56, default, default), (default, $57, default, default), (default, $58, default, default), (default, $59, default, default), (default, $60, default, default), (default, $61, default, default), (default, $62, default, default), (default, $63, default, default), (default, $64, default, default), (default, $65, default, default), (default, $66, default, default), (default, $67, default, default), (default, $68, default, default), (default, $69, default, default), (default, $70, default, default), (default, $71, default, default), (default, $72, default, default), (default, $73, default, default), (default, $74, default, default), (default, $75, default, default), (default, $76, default, default), (default, $77, default, default), (default, $78, default, default), (default, $79, default, default), (default, $80, default, default), (default, $81, default, default), (default, $82, default, default), (default, $83, default, default), (default, $84, default, default), (default, $85, default, default), (default, $86, default, default), (default, $87, default, default), (default, $88, default, default), (default, $89, default, default), (default, $90, default, default), (default, $91, default, default), (default, $92, default, default), (default, $93, default, default), (default, $94, default, default), (default, $95, default, default), (default, $96, default, default), (default, $97, default, default), (default, $98, default, default), (default, $99, default, default), (default, $100, default, default), (default, $101, default, default), (default, $102, default, default), (default, $103, default, default), (default, $104, default, default), (default, $105, default, default), (default, $106, default, default), (default, $107, default, default), (default, $108, default, default), (default, $109, default, default), (default, $110, default, default), (default, $111, default, default), (default, $112, default, default), (default, $113, default, default), (default, $114, default, default), (default, $115, default, default), (default, $116, default, default), (default, $117, default, default), (default, $118, default, default), (default, $119, default, default), (default, $120, default, default), (default, $121, default, default), (default, $122, default, default), (default, $123, default, default), (default, $124, default, default), (default, $125, default, default), (default, $126, default, default), (default, $127, default, default), (default, $128, default, default), (default, $129, default, default), (default, $130, default, default), (default, $131, default, default), (default, $132, default, default), (default, $133, default, default), (default, $134, default, default), (default, $135, default, default), (default, $136, default, default), (default, $137, default, default), (default, $138, default, default), (default, $139, default, default), (default, $140, default, default), (default, $141, default, default), (default, $142, default, default), (default, $143, default, default), (default, $144, default, default), (default, $145, default, default), (default, $146, default, default), (default, $147, default, default), (default, $148, default, default), (default, $149, default, default), (default, $150, default, default), (default, $151, default, default), (default, $152, default, default), (default, $153, default, default), (default, $154, default, default), (default, $155, default, default), (default, $156, default, default), (default, $157, default, default), (default, $158, default, default), (default, $159, default, default), (default, $160, default, default), (default, $161, default, default), (default, $162, default, default), (default, $163, default, default), (default, $164, default, default), (default, $165, default, default), (default, $166, default, default), (default, $167, default, default), (default, $168, default, default), (default, $169, default, default), (default, $170, default, default), (default, $171, default, default), (default, $172, default, default), (default, $173, default, default), (default, $174, default, default), (default, $175, default, default), (default, $176, default, default), (default, $177, default, default), (default, $178, default, default), (default, $179, default, default), (default, $180, default, default), (default, $181, default, default), (default, $182, default, default), (default, $183, default, default), (default, $184, default, default), (default, $185, default, default), (default, $186, default, default), (default, $187, default, default), (default, $188, default, default), (default, $189, default, default), (default, $190, default, default), (default, $191, default, default), (default, $192, default, default), (default, $193, default, default), (default, $194, default, default), (default, $195, default, default), (default, $196, default, default), (default, $197, default, default), (default, $198, default, default), (default, $199, default, default), (default, $200, default, default), (default, $201, default, default) -- params: [4, 4, 1, 3, 5, 1, 4, 6, 4, 2, 2, 4, 1, 4, 5, 6, 5, 5, 5, 6, 1, 5, 2, 2, 4, 3, 3, 3, 2, 2, 4, 4, 1, 2, 4, 2, 2, 4, 5, 2, 3, 6, 5, 2, 2, 5, 1, 2, 6, 2, 6, 5, 1, 6, 3, 2, 2, 3, 1, 4, 4, 5, 4, 2, 4, 5, 1, 5, 4, 4, 3, 2, 5, 2, 4, 2, 6, 5, 4, 5, 4, 3, 5, 2, 2, 5, 5, 5, 2, 4, 3, 3, 4, 5, 2, 5, 1, 2, 4, 4, 2, 1, 5, 2, 4, 4, 5, 4, 4, 2, 3, 4, 1, 5, 2, 2, 4, 6, 1, 1, 1, 2, 3, 2, 4, 1, 5, 6, 5, 5, 2, 3, 4, 5, 2, 4, 3, 5, 5, 6, 1, 4, 3, 1, 4, 5, 4, 6, 5, 5, 3, 1, 5, 6, 4, 2, 3, 5, 4, 6, 3, 1, 6, 6, 2, 4, 1, 2, 4, 2, 3, 6, 3, 6, 1, 2, 4, 5, 1, 4, 4, 1, 6, 1, 4, 6, 6, 2, 5, 3, 1, 2, 1, 6, 3, 6, 2, 5, 2, 3, 0]
2024-10-14T22:36:38.608Z	5b6a8284-c83c-4614-a4cf-e95a8a38123e	INFO	Batch 1
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for GET: true
Sentry Logger [log]: [Tracing] Starting sampled span
op: < unknown op >
name: GET
ID: 233e958452256270
parent ID: 2627aa12341d8ca8
root ID: 2627aa12341d8ca8
root op: function.aws.lambda
root description: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "GET" with ID 233e958452256270
Sentry Logger [log]: SpanExporter has 2 unsent spans remaining
2024-10-14T22:36:39.790Z	5b6a8284-c83c-4614-a4cf-e95a8a38123e	INFO	Query: insert into "numbers" ("id", "number", "createdAt", "updatedAt") values (default, $1, default, default), (default, $2, default, default), (default, $3, default, default), (default, $4, default, default), (default, $5, default, default), (default, $6, default, default), (default, $7, default, default), (default, $8, default, default), (default, $9, default, default), (default, $10, default, default), (default, $11, default, default), (default, $12, default, default), (default, $13, default, default), (default, $14, default, default), (default, $15, default, default), (default, $16, default, default), (default, $17, default, default), (default, $18, default, default), (default, $19, default, default), (default, $20, default, default), (default, $21, default, default), (default, $22, default, default), (default, $23, default, default), (default, $24, default, default), (default, $25, default, default), (default, $26, default, default), (default, $27, default, default), (default, $28, default, default), (default, $29, default, default), (default, $30, default, default), (default, $31, default, default), (default, $32, default, default), (default, $33, default, default), (default, $34, default, default), (default, $35, default, default), (default, $36, default, default), (default, $37, default, default), (default, $38, default, default), (default, $39, default, default), (default, $40, default, default), (default, $41, default, default), (default, $42, default, default), (default, $43, default, default), (default, $44, default, default), (default, $45, default, default), (default, $46, default, default), (default, $47, default, default), (default, $48, default, default), (default, $49, default, default), (default, $50, default, default), (default, $51, default, default), (default, $52, default, default), (default, $53, default, default), (default, $54, default, default), (default, $55, default, default), (default, $56, default, default), (default, $57, default, default), (default, $58, default, default), (default, $59, default, default), (default, $60, default, default), (default, $61, default, default), (default, $62, default, default), (default, $63, default, default), (default, $64, default, default), (default, $65, default, default), (default, $66, default, default), (default, $67, default, default), (default, $68, default, default), (default, $69, default, default), (default, $70, default, default), (default, $71, default, default), (default, $72, default, default), (default, $73, default, default), (default, $74, default, default), (default, $75, default, default), (default, $76, default, default), (default, $77, default, default), (default, $78, default, default), (default, $79, default, default), (default, $80, default, default), (default, $81, default, default), (default, $82, default, default), (default, $83, default, default), (default, $84, default, default), (default, $85, default, default), (default, $86, default, default), (default, $87, default, default), (default, $88, default, default), (default, $89, default, default), (default, $90, default, default), (default, $91, default, default), (default, $92, default, default), (default, $93, default, default), (default, $94, default, default), (default, $95, default, default), (default, $96, default, default), (default, $97, default, default), (default, $98, default, default), (default, $99, default, default), (default, $100, default, default), (default, $101, default, default), (default, $102, default, default), (default, $103, default, default), (default, $104, default, default), (default, $105, default, default), (default, $106, default, default), (default, $107, default, default), (default, $108, default, default), (default, $109, default, default), (default, $110, default, default), (default, $111, default, default), (default, $112, default, default), (default, $113, default, default), (default, $114, default, default), (default, $115, default, default), (default, $116, default, default), (default, $117, default, default), (default, $118, default, default), (default, $119, default, default), (default, $120, default, default), (default, $121, default, default), (default, $122, default, default), (default, $123, default, default), (default, $124, default, default), (default, $125, default, default), (default, $126, default, default), (default, $127, default, default), (default, $128, default, default), (default, $129, default, default), (default, $130, default, default), (default, $131, default, default), (default, $132, default, default), (default, $133, default, default), (default, $134, default, default), (default, $135, default, default), (default, $136, default, default), (default, $137, default, default), (default, $138, default, default), (default, $139, default, default), (default, $140, default, default), (default, $141, default, default), (default, $142, default, default), (default, $143, default, default), (default, $144, default, default), (default, $145, default, default), (default, $146, default, default), (default, $147, default, default), (default, $148, default, default), (default, $149, default, default), (default, $150, default, default), (default, $151, default, default), (default, $152, default, default), (default, $153, default, default), (default, $154, default, default), (default, $155, default, default), (default, $156, default, default), (default, $157, default, default), (default, $158, default, default), (default, $159, default, default), (default, $160, default, default), (default, $161, default, default), (default, $162, default, default), (default, $163, default, default), (default, $164, default, default), (default, $165, default, default), (default, $166, default, default), (default, $167, default, default), (default, $168, default, default), (default, $169, default, default), (default, $170, default, default), (default, $171, default, default), (default, $172, default, default), (default, $173, default, default), (default, $174, default, default), (default, $175, default, default), (default, $176, default, default), (default, $177, default, default), (default, $178, default, default), (default, $179, default, default), (default, $180, default, default), (default, $181, default, default), (default, $182, default, default), (default, $183, default, default), (default, $184, default, default), (default, $185, default, default), (default, $186, default, default), (default, $187, default, default), (default, $188, default, default), (default, $189, default, default), (default, $190, default, default), (default, $191, default, default), (default, $192, default, default), (default, $193, default, default), (default, $194, default, default), (default, $195, default, default), (default, $196, default, default), (default, $197, default, default), (default, $198, default, default), (default, $199, default, default), (default, $200, default, default), (default, $201, default, default) -- params: [1, 3, 6, 6, 1, 1, 4, 4, 1, 3, 2, 2, 6, 1, 6, 6, 3, 5, 5, 2, 6, 1, 2, 1, 6, 3, 1, 5, 3, 4, 5, 4, 5, 3, 2, 3, 1, 2, 6, 5, 6, 1, 3, 1, 1, 2, 1, 5, 2, 5, 2, 3, 3, 5, 1, 1, 6, 6, 3, 5, 5, 3, 5, 1, 5, 2, 2, 6, 2, 1, 5, 4, 3, 1, 1, 3, 1, 6, 5, 3, 4, 2, 4, 5, 1, 3, 1, 3, 1, 6, 4, 4, 5, 6, 6, 4, 6, 2, 2, 3, 2, 1, 1, 6, 3, 1, 3, 6, 5, 2, 1, 6, 5, 4, 4, 4, 5, 3, 3, 5, 6, 6, 5, 3, 3, 5, 3, 5, 5, 5, 4, 2, 4, 1, 6, 2, 3, 2, 6, 2, 3, 1, 1, 1, 6, 5, 6, 3, 5, 4, 1, 3, 3, 4, 1, 1, 2, 3, 3, 5, 4, 5, 3, 3, 1, 2, 2, 4, 6, 2, 6, 6, 1, 4, 4, 4, 2, 2, 6, 3, 2, 6, 3, 5, 1, 5, 1, 2, 5, 2, 5, 5, 3, 2, 4, 2, 3, 3, 3, 5, 0]
Sentry Logger [log]: [Tracing] Finishing "function.aws.lambda" root span "aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N" with ID 2627aa12341d8ca8
Sentry Logger [log]: [Profiling] stopped profiling of transaction: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
Sentry Logger [log]: SpanExporter exported 3 spans, 0 unsent spans remaining
Sentry Logger [log]: Flushing outcomes...
Sentry Logger [log]: No outcomes to send
Sentry Logger [log]: [Tracing] Finishing "function.aws.lambda" root span "aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N" with ID 434e5358e922b78b
Sentry Logger [log]: [Profiling] stopped profiling of transaction: aws-sam-ts-pg-sentry-HelloWorldFunction-KrbK1K8cre4N
Sentry Logger [error]: Spans may not be exported for the lambda function because we are not force flushing before callback.
Sentry Logger [error]: Metrics may not be exported for the lambda function because we are not force flushing before callback.
END RequestId: 5b6a8284-c83c-4614-a4cf-e95a8a38123e
REPORT RequestId: 5b6a8284-c83c-4614-a4cf-e95a8a38123e	Duration: 7404.69 ms	Billed Duration: 7405 ms	Memory Size: 128 MB	Max Memory Used: 119 MB	Init Duration: 532.32 ms
@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Oct 14, 2024
@github-actions github-actions bot added the Package: aws-serverless Issues related to the Sentry AWS Serverless SDK label Oct 14, 2024
@andreiborza
Copy link
Member

Hi @ffraenz, thank you for filing this and providing comprehensive reproduction. I ran through your repo and can confirm the same outcome.

We're going to investigate this further, it might be related to drizzle - we've had problems with it in the past, although those were related to ESM and opentelemetry wrapping.

@ffraenz
Copy link
Author

ffraenz commented Oct 16, 2024

I've added a second test case to the repository, using Sentry with pg, leaving out Drizzle.js. I get the same unexpected outcome. It doesn't seem to be related to Drizzle 🤔

Image

Link to Sentry event

function-pg logs from AWS CloudWatch
INIT_START Runtime Version: nodejs:20.v39	Runtime Version ARN: arn:aws:lambda:eu-central-1::runtime:83d84646b3540dd38341195452110b2178a7231400ce6bc20c6179e5b297ae04
--
Sentry Logger [log]: Initializing Sentry: process: 2, thread: main.
Sentry Logger [log]: Integration installed: InboundFilters
Sentry Logger [log]: Integration installed: FunctionToString
Sentry Logger [log]: Integration installed: LinkedErrors
Sentry Logger [log]: Integration installed: RequestData
Sentry Logger [log]: Integration installed: Console
Sentry Logger [log]: Integration installed: Http
Sentry Logger [log]: Integration installed: NodeFetch
Sentry Logger [log]: Integration installed: OnUncaughtException
Sentry Logger [log]: Integration installed: OnUnhandledRejection
Sentry Logger [log]: Integration installed: ContextLines
Sentry Logger [log]: Integration installed: LocalVariablesAsync
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: Modules
Sentry Logger [log]: Integration installed: Aws
Sentry Logger [log]: Integration installed: AwsLambda
Sentry Logger [log]: [Profiling] Profiling integration setup.
Sentry Logger [log]: [Profiling] Span profiler mode enabled.
Sentry Logger [log]: Integration installed: ProfilingIntegration
Sentry Logger [log]: Integration installed: Postgres
Sentry Logger [log]: Running in CommonJS mode.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [warn]: Failed extracting version /var/task
Sentry Logger [debug]: @opentelemetry/instrumentation-aws-lambda Applying instrumentation patch for nodejs module file on require hook {
module: '/var/task/app.js',
version: undefined,
fileName: 'app',
baseDir: '/var/task'
}
Sentry Logger [debug]: patch handler function
START RequestId: 8163cb20-5413-43ec-bfb7-d3cfc62e98c6 Version: $LATEST
Sentry Logger [log]: [Tracing] Starting sampled root span
op: < unknown op >
name: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
ID: c7b15edfce96aa1f
Sentry Logger [log]: [Profiling] started profiling transaction: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
Sentry Logger [log]: [Tracing] Starting sampled root span
op: function.aws.lambda
name: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
ID: a00090b7e617307a
Sentry Logger [log]: [Profiling] started profiling transaction: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
2024-10-16T07:36:09.063Z	8163cb20-5413-43ec-bfb7-d3cfc62e98c6	INFO	Batch 0
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for GET: true
Sentry Logger [log]: [Tracing] Starting sampled span
op: < unknown op >
name: GET
ID: 9afc1f2ee1a6ed9b
parent ID: a00090b7e617307a
root ID: a00090b7e617307a
root op: function.aws.lambda
root description: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "GET" with ID 9afc1f2ee1a6ed9b
Sentry Logger [log]: SpanExporter has 1 unsent spans remaining
2024-10-16T07:36:10.244Z	8163cb20-5413-43ec-bfb7-d3cfc62e98c6	INFO	Query: insert into "numbers" ("number") values ($1), ($2), ($3), ($4), ($5), ($6), ($7), ($8), ($9), ($10), ($11), ($12), ($13), ($14), ($15), ($16), ($17), ($18), ($19), ($20), ($21), ($22), ($23), ($24), ($25), ($26), ($27), ($28), ($29), ($30), ($31), ($32), ($33), ($34), ($35), ($36), ($37), ($38), ($39), ($40), ($41), ($42), ($43), ($44), ($45), ($46), ($47), ($48), ($49), ($50), ($51), ($52), ($53), ($54), ($55), ($56), ($57), ($58), ($59), ($60), ($61), ($62), ($63), ($64), ($65), ($66), ($67), ($68), ($69), ($70), ($71), ($72), ($73), ($74), ($75), ($76), ($77), ($78), ($79), ($80), ($81), ($82), ($83), ($84), ($85), ($86), ($87), ($88), ($89), ($90), ($91), ($92), ($93), ($94), ($95), ($96), ($97), ($98), ($99), ($100), ($101), ($102), ($103), ($104), ($105), ($106), ($107), ($108), ($109), ($110), ($111), ($112), ($113), ($114), ($115), ($116), ($117), ($118), ($119), ($120), ($121), ($122), ($123), ($124), ($125), ($126), ($127), ($128), ($129), ($130), ($131), ($132), ($133), ($134), ($135), ($136), ($137), ($138), ($139), ($140), ($141), ($142), ($143), ($144), ($145), ($146), ($147), ($148), ($149), ($150), ($151), ($152), ($153), ($154), ($155), ($156), ($157), ($158), ($159), ($160), ($161), ($162), ($163), ($164), ($165), ($166), ($167), ($168), ($169), ($170), ($171), ($172), ($173), ($174), ($175), ($176), ($177), ($178), ($179), ($180), ($181), ($182), ($183), ($184), ($185), ($186), ($187), ($188), ($189), ($190), ($191), ($192), ($193), ($194), ($195), ($196), ($197), ($198), ($199), ($200), ($201)
2024-10-16T07:36:10.642Z	8163cb20-5413-43ec-bfb7-d3cfc62e98c6	INFO	Batch 1
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for GET: true
Sentry Logger [log]: [Tracing] Starting sampled span
op: < unknown op >
name: GET
ID: 81401f53e82e5740
parent ID: a00090b7e617307a
root ID: a00090b7e617307a
root op: function.aws.lambda
root description: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "GET" with ID 81401f53e82e5740
Sentry Logger [log]: SpanExporter has 2 unsent spans remaining
2024-10-16T07:36:12.202Z	8163cb20-5413-43ec-bfb7-d3cfc62e98c6	INFO	Query: insert into "numbers" ("number") values ($1), ($2), ($3), ($4), ($5), ($6), ($7), ($8), ($9), ($10), ($11), ($12), ($13), ($14), ($15), ($16), ($17), ($18), ($19), ($20), ($21), ($22), ($23), ($24), ($25), ($26), ($27), ($28), ($29), ($30), ($31), ($32), ($33), ($34), ($35), ($36), ($37), ($38), ($39), ($40), ($41), ($42), ($43), ($44), ($45), ($46), ($47), ($48), ($49), ($50), ($51), ($52), ($53), ($54), ($55), ($56), ($57), ($58), ($59), ($60), ($61), ($62), ($63), ($64), ($65), ($66), ($67), ($68), ($69), ($70), ($71), ($72), ($73), ($74), ($75), ($76), ($77), ($78), ($79), ($80), ($81), ($82), ($83), ($84), ($85), ($86), ($87), ($88), ($89), ($90), ($91), ($92), ($93), ($94), ($95), ($96), ($97), ($98), ($99), ($100), ($101), ($102), ($103), ($104), ($105), ($106), ($107), ($108), ($109), ($110), ($111), ($112), ($113), ($114), ($115), ($116), ($117), ($118), ($119), ($120), ($121), ($122), ($123), ($124), ($125), ($126), ($127), ($128), ($129), ($130), ($131), ($132), ($133), ($134), ($135), ($136), ($137), ($138), ($139), ($140), ($141), ($142), ($143), ($144), ($145), ($146), ($147), ($148), ($149), ($150), ($151), ($152), ($153), ($154), ($155), ($156), ($157), ($158), ($159), ($160), ($161), ($162), ($163), ($164), ($165), ($166), ($167), ($168), ($169), ($170), ($171), ($172), ($173), ($174), ($175), ($176), ($177), ($178), ($179), ($180), ($181), ($182), ($183), ($184), ($185), ($186), ($187), ($188), ($189), ($190), ($191), ($192), ($193), ($194), ($195), ($196), ($197), ($198), ($199), ($200), ($201)
Sentry Logger [log]: [Tracing] Finishing "function.aws.lambda" root span "aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5" with ID a00090b7e617307a
Sentry Logger [log]: [Profiling] stopped profiling of transaction: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
Sentry Logger [log]: SpanExporter exported 3 spans, 0 unsent spans remaining
Sentry Logger [log]: Flushing outcomes...
Sentry Logger [log]: No outcomes to send
Sentry Logger [log]: [Tracing] Finishing "function.aws.lambda" root span "aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5" with ID c7b15edfce96aa1f
Sentry Logger [log]: [Profiling] stopped profiling of transaction: aws-sam-ts-pg-sentry-PgFunction-YhSyBCZNgEN5
Sentry Logger [error]: Spans may not be exported for the lambda function because we are not force flushing before callback.
Sentry Logger [error]: Metrics may not be exported for the lambda function because we are not force flushing before callback.
END RequestId: 8163cb20-5413-43ec-bfb7-d3cfc62e98c6
REPORT RequestId: 8163cb20-5413-43ec-bfb7-d3cfc62e98c6	Duration: 6386.21 ms	Billed Duration: 6387 ms	Memory Size: 128 MB	Max Memory Used: 121 MB	Init Duration: 521.29 ms

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Oct 16, 2024
@andreiborza
Copy link
Member

@ffraenz thanks for the second test case, that'll save time investigating drizzle :).

From the logs it's already weird that we're starting a second root span. That indicates that the lambda handler was not wrapped by otel correctly.

// Only start a trace and root span if the handler is not already wrapped by Otel instrumentation
// Otherwise, we create two root spans (one from otel, one from our wrapper).
// If Otel instrumentation didn't work or was filtered by users, we still want to trace the handler.
if (options.startTrace && !isWrappedByOtel(handler)) {
const traceData = getAwsTraceData(event as { headers?: Record<string, string> }, context);
return continueTrace({ sentryTrace: traceData['sentry-trace'], baggage: traceData.baggage }, () => {
return startSpanManual(
{
name: context.functionName,
op: 'function.aws.lambda',
attributes: {
[SEMANTIC_ATTRIBUTE_SENTRY_SOURCE]: 'component',
[SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN]: 'auto.function.serverless',
},
},
span => {
enhanceScopeWithTransactionData(getCurrentScope(), context);
return processResult(span);
},
);
});
}

I'll try to investigate that further.

Thanks again for providing great reproduction!

@andreiborza
Copy link
Member

I just tested your pg handler code in an node app and indeed everything was instrumented fine there, so it's probably not an issue with our pg instrumentation either.

Probably an issue with the aws-serverless sdk.

@andreiborza
Copy link
Member

@ffraenz we've figured out why there are no pg spans. Since you're using SAM with esbuild to bundle the lambda function, all the dependencies are bundled in as well, including pg. But opentelemetry needs to hook into pg and it can't do that if everything is bundled into our file.

Therefore, to get pg spans (and any other spans for libraries we support) you have to mark pg as external in your SAM template and create a lambda layer for it and attach that to your function.

From my testing, there are still Missing instrumentation spans in the UI for which I currently have no answer, but pg spans are working.

Image

@ffraenz
Copy link
Author

ffraenz commented Oct 18, 2024

I was not aware of the way opentelemetry hooks into pg via module requires/imports that are usually replaced with references to in-memory versions of the modules during esbuild bundling. I see that esbuild plugins for this use case are already being discussed: open-telemetry/opentelemetry-js#4174.

I try my best to avoid the added complexity of maintaining Lambda layers. Making pg external and providing it via a Lambda layer may lead to version mismatches. So, I'm wondering if manual spans might be the best way to deal with it in my code base. All SQL queries are already executed in a wrapper function of mine, which I could extend with such instrumentation logic. I can't assess if that solution could come close to what opentelemetry pg hooks have to offer, though, in addition to Sentry post processing.

As AWS SAM is one of the recommended ways to ship Node.js code on AWS Lambda, I think it makes sense to mention this limitation in the Sentry docs.

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Oct 18, 2024
@andreiborza
Copy link
Member

@ffraenz that's a good suggestion. As for Lambda Layer, yea I can understand.

You can have a look at what opteneltemetry instruments by looking at their tests.

Have a look at our docs for custom instrumentation to understand what sentry span apis you might want to use.

Lastly, I agree we should have some notes about bundled setups. I'l add it our backlog.

@andreiborza
Copy link
Member

I created a task to better document this in our backlog: #14028.

Thanks again for filing this @ffraenz.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Package: aws-serverless Issues related to the Sentry AWS Serverless SDK
Projects
Archived in project
Development

No branches or pull requests

2 participants