-
Notifications
You must be signed in to change notification settings - Fork 3.4k
Description
Describe the Bug
It seems like under some circumstances the connection with Azure Storage when fetching media is not properly terminated.
Our production server "active handles" counter keeps growing and when using the 'wtfnode' package to dump the handles we see this:
(1000+ active handles to Azure Storage)
25-07-29T09:38:35.6162665Z 09:38:35 0|server | - 159.224.121.7:56274 -> 20.60.234.4:443
2025-07-29T09:38:35.6238476Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/09770212-ef89-4204-ad46-69ef45507c36.png
2025-07-29T09:38:35.6244445Z 09:38:35 0|server | - 159.224.121.7:56282 -> 20.60.234.4:443
2025-07-29T09:38:35.6251832Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/51f2b8d8-2d62-4afa-b505-24315b4efbb7.png
2025-07-29T09:38:35.6332609Z 09:38:35 0|server | - 159.224.121.7:42210 -> 20.60.234.4:443
2025-07-29T09:38:35.6338548Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/0fa9e3f2-abd2-4765-88fc-5721c7af0a07.png
2025-07-29T09:38:35.6346916Z 09:38:35 0|server | - 159.224.121.7:35300 -> 20.60.234.4:443
2025-07-29T09:38:35.6354897Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/e6c67052-e76b-4c55-8330-ed8066ec97d0.png
2025-07-29T09:38:35.6435407Z 09:38:35 0|server | - 159.224.121.7:41780 -> 20.60.234.4:443
2025-07-29T09:38:35.6441600Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/43669a16-2694-4561-8b18-88b8a8918a41.png
2025-07-29T09:38:35.6449682Z 09:38:35 0|server | - 159.224.121.7:53042 -> 20.60.234.4:443
2025-07-29T09:38:35.6457670Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/1c0211a8-ff04-40b1-a6d1-81f4a6e8d514.png
2025-07-29T09:38:35.6537386Z 09:38:35 0|server | - 159.224.121.7:53052 -> 20.60.234.4:443
2025-07-29T09:38:35.6544397Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/52a0f04d-e651-4f04-9401-26d2225cfd3e.png
2025-07-29T09:38:35.6552353Z 09:38:35 0|server | - 159.224.121.7:47222 -> 20.60.234.4:443
2025-07-29T09:38:35.6559936Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/45330fdf-d03a-4885-ac16-c324801f7b8e.png
2025-07-29T09:38:35.6640477Z 09:38:35 0|server | - 159.224.121.7:47228 -> 20.60.234.4:443
2025-07-29T09:38:35.6647765Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/9fc8ad68-affd-4884-8595-3cb278b79c3c.png
2025-07-29T09:38:35.6655851Z 09:38:35 0|server | - 159.224.121.7:47240 -> 20.60.234.4:443
2025-07-29T09:38:35.6734691Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/13380ce5-db1a-40dd-af9c-e7c41c3ba4b5.png
2025-07-29T09:38:35.6741913Z 09:38:35 0|server | - 159.224.121.7:57028 -> 20.60.234.4:443
2025-07-29T09:38:35.6749870Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/1291152c-89be-4e4d-9682-301f6c1a4681.png
2025-07-29T09:38:35.6757999Z 09:38:35 0|server | - 159.224.121.7:57044 -> 20.60.234.4:443
2025-07-29T09:38:35.6837679Z 09:38:35 0|server | - GET https://someazurestorage.blob.core.windows.net/cms/media/51f2b8d8-2d62-4afa-b505-24315b4efbb7.png
After some time our logs are filled with ECONNRESET and timeout errors correlated to these Azure requests
2025-07-29T09:38:39.0341125Z 09:38:39 0|server | Error [AbortError]: The operation was aborted.
2025-07-29T09:38:39.0342146Z 09:38:39 0|server | at IncomingMessage.sourceAbortedHandler (.next/server/chunks/3725.js:213:169469)
2025-07-29T09:38:39.0342199Z 09:38:39 0|server | at <unknown> (.next/server/instrumentation.js:1:30339)
2025-07-29T09:38:39.0342277Z 09:38:39 0|server | at t.with (.next/server/instrumentation.js:1:33313)
2025-07-29T09:38:39.0342395Z 09:38:39 0|server | at t.with (.next/server/instrumentation.js:25:193810)
2025-07-29T09:38:39.0342433Z 09:38:39 0|server | at IncomingMessage.n (.next/server/instrumentation.js:1:30330)
2025-07-29T09:38:39.2769890Z 09:38:39 0|server | Error [AbortError]: The operation was aborted.
2025-07-29T09:38:39.2770647Z 09:38:39 0|server | at IncomingMessage.sourceAbortedHandler (.next/server/chunks/3725.js:213:169469)
2025-07-29T09:38:39.2771540Z 09:38:39 0|server | at <unknown> (.next/server/instrumentation.js:1:30339)
2025-07-29T09:38:39.2771911Z 09:38:39 0|server | at t.with (.next/server/instrumentation.js:1:33313)
2025-07-29T09:38:39.2771966Z 09:38:39 0|server | at t.with (.next/server/instrumentation.js:25:193810)
2025-07-29T09:38:39.2772013Z 09:38:39 0|server | at IncomingMessage.n (.next/server/instrumentation.js:1:30330)
2025-07-29T09:38:39.2782172Z 09:38:39 0|server | ⨯ uncaughtException: Error [AbortError]: The operation was aborted.
2025-07-29T09:38:39.2782707Z 09:38:39 0|server | at IncomingMessage.sourceAbortedHandler (.next/server/chunks/3725.js:213:169469)
2025-07-29T09:38:39.2782761Z 09:38:39 0|server | at <unknown> (.next/server/instrumentation.js:1:30339)
2025-07-29T09:38:39.2782851Z 09:38:39 0|server | at t.with (.next/server/instrumentation.js:1:33313)
2025-07-29T09:38:39.2782891Z 09:38:39 0|server | at t.with (.next/server/instrumentation.js:25:193810)
2025-07-29T09:38:39.2782927Z 09:38:39 0|server | at IncomingMessage.n (.next/server/instrumentation.js:1:30330)
2025-07-29T09:38:46.9673416Z 09:38:46 0|server | Error [AbortError]: The operation was aborted.
2025-07-29T09:38:46.9674218Z 09:38:46 0|server | at IncomingMessage.sourceAbortedHandler (.next/server/chunks/3725.js:213:169469)
2025-07-29T09:38:46.9674269Z 09:38:46 0|server | at <unknown> (.next/server/instrumentation.js:1:30339)
2025-07-29T09:38:46.9674354Z 09:38:46 0|server | at t.with (.next/server/instrumentation.js:1:33313)
2025-07-29T09:38:46.9674392Z 09:38:46 0|server | at t.with (.next/server/instrumentation.js:25:193810)
2025-07-29T09:38:46.9674446Z 09:38:46 0|server | at IncomingMessage.n (.next/server/instrumentation.js:1:30330)
Could it be related to automatic retries in Azure Storage Client and/or cancelled requests which are not handled correctly?
I also checked the S3 & Azure plugin differences and noticed the Azure plugin does not have any explicit stream destroying logic but the S3 implementation does.
Link to the code that reproduces this issue
https://github.com/taaviaun/payloadcms-azure-blob/tree/3dd394fdcffd0115e0c1a179c883d8930968a93f
Reproduction Steps
- Configure mongo & Azure env variables
- Start the server
npm run devor build standalone and run server.js - Upload some media via admin panel
- F5 spam the uploaded media image direct url (without the next/image proxy)
- Visit the
/debugroute to dump active handles to the console (these should remain for a long time)
NB! This behavior is very inconsistent and doesn't always happen, making it quite hard to reproduce and debug
Which area(s) are affected? (Select all that apply)
plugin: other
Environment Info
Binaries:
Node: 22.14.0
npm: N/A
Yarn: N/A
pnpm: N/A
Relevant Packages:
payload: 3.49.1
next: 15.4.4
@payloadcms/db-mongodb: 3.49.1
@payloadcms/email-nodemailer: 3.49.1
@payloadcms/graphql: 3.49.1
@payloadcms/next/utilities: 3.49.1
@payloadcms/payload-cloud: 3.49.1
@payloadcms/plugin-cloud-storage: 3.49.1
@payloadcms/richtext-lexical: 3.49.1
@payloadcms/storage-azure: 3.49.1
@payloadcms/translations: 3.49.1
@payloadcms/ui/shared: 3.49.1
react: 19.1.0
react-dom: 19.1.0
Operating System:
Platform: win32
Arch: x64
Version: Windows 11 Enterprise
Available memory (MB): 65242
Available CPU cores: 32