aws-sdk-js-v3
aws-sdk-js-v3 copied to clipboard
Published
20 hours ago •
aws
aws
Very slow parallel S3 GetObjectCommand executions (maxSockets)
Describe the bug
Executing many parallel S3 GetObjectCommand is extremely slow in direct comparison to v2 of the sdk at best, suspected of breaking Lambda executions at worst.
Your environment
SDK version number
@aws-sdk/[email protected]
Is the issue in the browser/Node.js/ReactNative?
Node.js
Details of the browser/Node.js/ReactNative version
node -v: v14.18.3
Steps to reproduce
I created a bucket containing 159 files (0 byte, size does not seem to be a factor). Then I created the same functionality of getting those files in parallel in minimal scripts for both v3 and v2 of the AWS sdk.
TS Code for v3:
import {
S3Client,
GetObjectCommand,
ListObjectsV2Command,
} from "@aws-sdk/client-s3";
const [nodePath, scriptPath, bucketName] = process.argv;
(async () => {
try {
const s3Client = new S3Client({
region: "us-east-1",
});
console.log(new Date().toISOString());
const files = await s3Client.send(
new ListObjectsV2Command({
Bucket: bucketName,
})
);
console.log(new Date().toISOString());
const getPromises = [];
if (files.Contents) {
for (const file of files.Contents) {
if (file.Key) {
getPromises.push(
s3Client.send(
new GetObjectCommand({
Bucket: bucketName,
Key: file.Key,
})
)
);
}
}
}
const result = await Promise.all(getPromises);
console.log(result.length);
} catch (e) {
console.log(e);
}
})();
TS Code for v2:
import S3 from "aws-sdk/clients/s3";
const [nodePath, scriptPath, bucketName] = process.argv;
(async () => {
try {
const s3Client = new S3({
region: "us-east-1",
});
console.log(new Date().toISOString());
const files = await s3Client
.listObjectsV2({
Bucket: bucketName,
})
.promise();
console.log(new Date().toISOString());
const getPromises = [];
if (files.Contents) {
for (const file of files.Contents) {
if (file.Key) {
getPromises.push(
s3Client.getObject({
Bucket: bucketName,
Key: file.Key!,
}).promise()
);
}
}
}
const result = await Promise.all(getPromises)
console.log(result.length)
} catch (e) {
console.log(e);
}
})();
Observed behavior
After transpiling, I executed both versions multiple times via time node dist/index.js <bucket-name>. There is a huge gap in the execution time between them. I added logs of the timestamp before and after the listObjects command to verify that command isn't the actual issue.
Representative outputs for the difference in execution time I experienced across all runs consistently:
v2
aws-sdk-v2$ time node dist/index.js <bucket-name>
2022-04-25T13:04:08.423Z
2022-04-25T13:04:09.580Z
159
real 0m1,352s
user 0m0,314s
sys 0m0,009s
v3
aws-sdk-v3$ time node dist/index.js <bucket-name>
2022-04-25T13:03:18.831Z
2022-04-25T13:03:19.996Z
159
real 0m27,881s
user 0m1,456s
sys 0m0,176s
On my machine, it's "just" 20 times slower - a lambda function I have which does a similar thing (albeit with more files - around 1100) now after migration from v2 to v3 just returns "null" at that point in the execution when that is not an available return value in any of the execution paths of the code. No error message logged that I could provide unfortunately.
Expected behavior
Similar speed to v2 of the sdk in general, not just ending a Lambda execution.
Screenshots
Additional context
Your v2 repro code isn't calling .promise() on the s3Client.getObject(...) calls, so your Promise.all(...) isn't actually waiting for anything. You can confirm this by hovering result and seeing what TypeScript thinks the type is.
Thanks a lot for the heads up @Roryl-c , I missed that one. Corrected in an edit above as to send noone down the wrong path. Correcting the code there gets some improvement - we're now still looking at a 12 times worse performance on V3 though.
New representative output (including a console.log of the first element of the result to verify correct operation):
V2:
aws-sdk-v2$ time node dist/index.js <bucket_name>
2022-04-26T04:14:04.309Z
2022-04-26T04:14:05.326Z
159
{
AcceptRanges: 'bytes',
LastModified: 2022-04-25T12:48:57.000Z,
ContentLength: 0,
ETag: '"d41d8cd98f00b204e9800998ecf8427e"',
ContentType: 'binary/octet-stream',
Metadata: {},
Body: <Buffer >
}
real 0m2,557s
user 0m0,764s
sys 0m0,061s
V3:
Thanks a lot for the heads up @Roryl-c , I missed that one. Corrected in an edit above.
Correcting the code there gets some improvement - we're now still looking at a 12 times worse performance on v3 though.
aws-sdk-v3$ time node dist/index.js <bucket_name>
2022-04-26T04:14:23.927Z
2022-04-26T04:14:25.164Z
159
{
'$metadata': {
httpStatusCode: 200,
requestId: undefined,
extendedRequestId: 'oaX1SPWbVP+SbotZ5EtrxulYZEMyVU8+JtrrjpoGHi1pXXQsxWvBqjy8V2uQ99SkpmxI1wS1+cE=',
cfId: undefined,
attempts: 1,
totalRetryDelay: 0
},
AcceptRanges: 'bytes',
Body: <ref *1> IncomingMessage {
_readableState: ReadableState {
objectMode: false,
highWaterMark: 16384,
buffer: BufferList { head: null, tail: null, length: 0 },
length: 0,
pipes: [],
flowing: null,
ended: true,
endEmitted: false,
reading: false,
sync: true,
needReadable: false,
emittedReadable: false,
readableListening: false,
resumeScheduled: false,
errorEmitted: false,
emitClose: true,
autoDestroy: false,
destroyed: false,
errored: null,
closed: false,
closeEmitted: false,
defaultEncoding: 'utf8',
awaitDrainWriters: null,
multiAwaitDrain: false,
readingMore: true,
dataEmitted: false,
decoder: null,
encoding: null,
[Symbol(kPaused)]: null
},
_events: [Object: null prototype] { end: [Array] },
_eventsCount: 1,
_maxListeners: undefined,
socket: TLSSocket {
_tlsOptions: [Object],
_secureEstablished: true,
_securePending: false,
_newSessionPending: false,
_controlReleased: true,
secureConnecting: false,
_SNICallback: null,
servername: '<bucket_name>.s3.us-east-1.amazonaws.com',
alpnProtocol: false,
authorized: true,
authorizationError: null,
encrypted: true,
_events: [Object: null prototype],
_eventsCount: 9,
connecting: false,
_hadError: false,
_parent: null,
_host: '<bucket_name>.s3.us-east-1.amazonaws.com',
_readableState: [ReadableState],
_maxListeners: undefined,
_writableState: [WritableState],
allowHalfOpen: false,
_sockname: null,
_pendingData: null,
_pendingEncoding: '',
server: undefined,
_server: null,
ssl: null,
_requestCert: true,
_rejectUnauthorized: true,
parser: null,
_httpMessage: [ClientRequest],
timeout: 0,
write: [Function: writeAfterFIN],
[Symbol(res)]: null,
[Symbol(verified)]: true,
[Symbol(pendingSession)]: null,
[Symbol(async_id_symbol)]: 48,
[Symbol(kHandle)]: null,
[Symbol(kSetNoDelay)]: false,
[Symbol(lastWriteQueueSize)]: 0,
[Symbol(timeout)]: null,
[Symbol(kBuffer)]: null,
[Symbol(kBufferCb)]: null,
[Symbol(kBufferGen)]: null,
[Symbol(kCapture)]: false,
[Symbol(kBytesRead)]: 34826,
[Symbol(kBytesWritten)]: 3387,
[Symbol(connect-options)]: [Object],
[Symbol(RequestTimeout)]: undefined
},
httpVersionMajor: 1,
httpVersionMinor: 1,
httpVersion: '1.1',
complete: true,
headers: {
'x-amz-id-2': 'oaX1SPWbVP+SbotZ5EtrxulYZEMyVU8+JtrrjpoGHi1pXXQsxWvBqjy8V2uQ99SkpmxI1wS1+cE=',
'x-amz-request-id': '8YZSWGXFWP7F92XJ',
date: 'Tue, 26 Apr 2022 04:14:26 GMT',
'last-modified': 'Mon, 25 Apr 2022 12:48:57 GMT',
etag: '"d41d8cd98f00b204e9800998ecf8427e"',
'accept-ranges': 'bytes',
'content-type': 'binary/octet-stream',
server: 'AmazonS3',
'content-length': '0'
},
rawHeaders: [
'x-amz-id-2',
'oaX1SPWbVP+SbotZ5EtrxulYZEMyVU8+JtrrjpoGHi1pXXQsxWvBqjy8V2uQ99SkpmxI1wS1+cE=',
'x-amz-request-id',
'8YZSWGXFWP7F92XJ',
'Date',
'Tue, 26 Apr 2022 04:14:26 GMT',
'Last-Modified',
'Mon, 25 Apr 2022 12:48:57 GMT',
'ETag',
'"d41d8cd98f00b204e9800998ecf8427e"',
'Accept-Ranges',
'bytes',
'Content-Type',
'binary/octet-stream',
'Server',
'AmazonS3',
'Content-Length',
'0'
],
trailers: {},
rawTrailers: [],
aborted: false,
upgrade: false,
url: '',
method: null,
statusCode: 200,
statusMessage: 'OK',
client: TLSSocket {
_tlsOptions: [Object],
_secureEstablished: true,
_securePending: false,
_newSessionPending: false,
_controlReleased: true,
secureConnecting: false,
_SNICallback: null,
servername: '<bucket_name>.s3.us-east-1.amazonaws.com',
alpnProtocol: false,
authorized: true,
authorizationError: null,
encrypted: true,
_events: [Object: null prototype],
_eventsCount: 9,
connecting: false,
_hadError: false,
_parent: null,
_host: '<bucket_name>.s3.us-east-1.amazonaws.com',
_readableState: [ReadableState],
_maxListeners: undefined,
_writableState: [WritableState],
allowHalfOpen: false,
_sockname: null,
_pendingData: null,
_pendingEncoding: '',
server: undefined,
_server: null,
ssl: null,
_requestCert: true,
_rejectUnauthorized: true,
parser: null,
_httpMessage: [ClientRequest],
timeout: 0,
write: [Function: writeAfterFIN],
[Symbol(res)]: null,
[Symbol(verified)]: true,
[Symbol(pendingSession)]: null,
[Symbol(async_id_symbol)]: 48,
[Symbol(kHandle)]: null,
[Symbol(kSetNoDelay)]: false,
[Symbol(lastWriteQueueSize)]: 0,
[Symbol(timeout)]: null,
[Symbol(kBuffer)]: null,
[Symbol(kBufferCb)]: null,
[Symbol(kBufferGen)]: null,
[Symbol(kCapture)]: false,
[Symbol(kBytesRead)]: 34826,
[Symbol(kBytesWritten)]: 3387,
[Symbol(connect-options)]: [Object],
[Symbol(RequestTimeout)]: undefined
},
_consuming: false,
_dumped: false,
req: ClientRequest {
_events: [Object: null prototype],
_eventsCount: 4,
_maxListeners: undefined,
outputData: [],
outputSize: 0,
writable: true,
destroyed: true,
_last: true,
chunkedEncoding: false,
shouldKeepAlive: true,
_defaultKeepAlive: true,
useChunkedEncodingByDefault: false,
sendDate: false,
_removedConnection: false,
_removedContLen: false,
_removedTE: false,
_contentLength: 0,
_hasBody: true,
_trailer: '',
finished: true,
_headerSent: true,
socket: [TLSSocket],
_header: '<REDACTED>',
_keepAliveTimeout: 0,
_onPendingData: [Function: noopPendingOutput],
agent: [Agent],
socketPath: undefined,
method: 'GET',
maxHeaderSize: undefined,
insecureHTTPParser: undefined,
path: '/027f19cca4a7119da720?x-id=GetObject',
_ended: false,
res: [Circular *1],
aborted: false,
timeoutCb: [Function: emitRequestTimeout],
upgradeOrConnect: false,
parser: null,
maxHeadersCount: null,
reusedSocket: true,
host: '<bucket_name>.s3.us-east-1.amazonaws.com',
protocol: 'https:',
[Symbol(kCapture)]: false,
[Symbol(kNeedDrain)]: false,
[Symbol(corked)]: 0,
[Symbol(kOutHeaders)]: [Object: null prototype]
},
[Symbol(kCapture)]: false,
[Symbol(RequestTimeout)]: undefined
},
BucketKeyEnabled: undefined,
CacheControl: undefined,
ChecksumCRC32: undefined,
ChecksumCRC32C: undefined,
ChecksumSHA1: undefined,
ChecksumSHA256: undefined,
ContentDisposition: undefined,
ContentEncoding: undefined,
ContentLanguage: undefined,
ContentLength: 0,
ContentRange: undefined,
ContentType: 'binary/octet-stream',
DeleteMarker: undefined,
ETag: '"d41d8cd98f00b204e9800998ecf8427e"',
Expiration: undefined,
Expires: undefined,
LastModified: 2022-04-25T12:48:57.000Z,
Metadata: {},
MissingMeta: undefined,
ObjectLockLegalHoldStatus: undefined,
ObjectLockMode: undefined,
ObjectLockRetainUntilDate: undefined,
PartsCount: undefined,
ReplicationStatus: undefined,
RequestCharged: undefined,
Restore: undefined,
SSECustomerAlgorithm: undefined,
SSECustomerKeyMD5: undefined,
SSEKMSKeyId: undefined,
ServerSideEncryption: undefined,
StorageClass: undefined,
TagCount: undefined,
VersionId: undefined,
WebsiteRedirectLocation: undefined
}
real 0m28,922s
user 0m1,799s
sys 0m0,213s
Also crosschecked the Lambda code I mentioned, thankfully didn't miss the .promise() in the V2 implementation there. After reverting to V2 just for that specific functionality (the rest of the Lambda still runs on V3), it works again.
@robert-hanuschke Hi! Thanks for bringing this to our attention.
I was able to reproduce your findings observing these 2 scenarios:
Running the code for 87 items in S3 bucket: V3:
Time isntantiate s3 client: 136.60179090499878ms
Time to list objects in bucket: 654.9991250038147ms
87 subsequent GetObject calls: 7387.941290855408ms
V2:
Time isntantiate s3 client: 79.35779213905334ms
Time to list objects in bucket: 646.8728330135345ms
87 subsequent GetObject calls: 861.3942501544952ms
Running the code with 1 item in S3 bucket: V3:
Time isntantiate s3 client: 138.31212520599365ms
Time to list objects in bucket: 498.3790419101715ms
1 subsequent GetObject calls: 251.10545825958252 ms
V2:
Time isntantiate s3 client: 99.40116715431213ms
Time to list objects in bucket: 535.6090829372406ms
1 subsequent GetObject calls: 524.4567511081696ms
It appears that fetching more subsequent calls causes performance issues in V3, however single or fewer reads are faster in V3.
@trivikr, based on your suggestion I have inspected the CPU usage of the provided example and found out that for the multiple item reads from the bucket is in fact a subsequent call of getOjectCommand, more specifically:
@aws-sdk/node-http-handler/dist-cjs/node-http-handler.js 49:28
Im forwarding it to the dev team for further investigation.
Hi @robert-hanuschke ,
I recognize that these kind of edge cases can be frustrating; however, we prioritize fixes and features based on community engagement and feedback. At this time there is no plan to address this issue. If anything changes I will certainly let you know.
Many thanks!
Hi Ran,
thanks for reopening. I was worried it would be completely forgotten if closed. It having lower priority if it's an edge case I totally understand.
For the time being I can live with the workaround of having this call still on the old sdk and hope this issue helps people stumbling across it who are in the same situation.
I have witnessed something similar. Many keys retrieved my making an array of promises, where each promise reuses the same client and sends a GetObjectCommand instance will execute what seems like in sequence, instead of "in parallel" like we'd expect from promise.all.
What I can add though, is when in the same promise, I iterate through the stream and convert to a buffer, then the promises are properly executed in what seems like parallel.
A minimal code example here:
import { GetObjectCommand, S3Client } from '@aws-sdk/client-s3';
import { Readable } from 'stream';
import { BUCKET, KEYS } from './keys';
export function streamToBuffer(stream: Readable): Promise<Buffer> {
return new Promise((resolve, reject) => {
const chunks: Uint8Array[] = [];
stream.on('data', (chunk) => chunks.push(chunk));
stream.on('error', reject);
stream.on('end', () => resolve(Buffer.concat(chunks)));
});
}
export async function getObjectsFast(client: S3Client, bucket: string, keys: string[]): Promise<any[]> {
return Promise.all(keys.map(key => getObjectFast(client, bucket, key)));
}
async function getObjectFast(client: S3Client, bucket: string, key: string): Promise<any> {
const command = new GetObjectCommand({ Bucket: bucket, Key: key });
const result = await client.send(command);
const buffer = await streamToBuffer(result.Body as Readable);
return buffer;
}
async function getObjectSlow(client: S3Client, bucket: string, key: string): Promise<any> {
const command = new GetObjectCommand({ Bucket: bucket, Key: key });
const result = await client.send(command);
return result;
}
export async function getObjectsSlow(client: S3Client, bucket: string, keys: string[]): Promise<any[]> {
return Promise.all(keys.map(key => getObjectSlow(client, bucket, key)));
}
async function run() {
const client = new S3Client({ region: 'ap-southeast-2' });
console.log(KEYS.length); // 75
const t1 = new Date();
await getObjectsFast(client, BUCKET, KEYS);
console.log('took1:', new Date().valueOf() - t1.valueOf()); // 260
const t2 = new Date();
await getObjectsSlow(client, BUCKET, KEYS);
console.log('took2:', new Date().valueOf() - t2.valueOf()); //6200
}
void run();
3.121.0 of the lib Node v14.17.6
I recently ran into a very similar situation, where doing a lot of GetObjectCommands in rapid succession would slow down tremendously and eventually lock up the process. Our current workaround is to make a new client instance for each GetObjectCommand and destroying it as soon as the read is done:
// Before
const client = new S3Client();
async function getFileStream() {
const response = await client.send(new GetObjectCommand({ Bucket, Key }));
return response.Body;
}
// After
async function getFileStream() {
const client = new S3Client();
const response = await client.send(new GetObjectCommand({ Bucket, Key }));
response.Body.on('finished', () => client.destroy());
return response.Body;
}
I thought that the issue before might've been caused by the default keepAlive behavior of the SDK, but explicitly disabling that and lowering the maxSockets didn't seem to resolve the problem fully 🤔
@rijkvanzanten
I was able to reproduce this issue recently and found a solution. The problem as I can see comes from two areas:
- a small default socket pool from the HTTPS agent
- the lack of socket timeout that may leak sockets from certain scenarios (e.g. if you pipe the response.Body to another stream and the other stream dies prematurely)
Once the HTTP Agent sockets are all in use, the S3Clients will hang. Your "new client per instance" will work, but you pay a big performance penalty for the huge resource allocations for every request, and losing the TLS session cache and HTTP keep-alive.
Here's a setting I find that works in my environment. You can tune the maxSockets and socketTimeout to your environment.
const s3 = new S3Client({
// Use a custom request handler so that we can adjust the HTTPS Agent and
// socket behavior.
requestHandler: new NodeHttpHandler({
httpsAgent: new Agent({
maxSockets: 500,
// keepAlive is a default from AWS SDK. We want to preserve this for
// performance reasons.
keepAlive: true,
keepAliveMsecs: 1000,
}),
socketTimeout: 5000,
}),
});
Great solution @askldjd! Thanks for sharing 😄 Very curious to see what changed between v2 and v3 in the handling of those sockets which now causes the socket to hang rather than cleanup.
That's a good question. If I am reading correctly, V2 defaults the timeout to 2 minutes. However, V3 defaults the timeout to zero.
That might be the root cause.
Hi everyone,
Thank you for continuing commenting and providing information. @samjarman Thank you for the repro code, and @askldjd thanks for the workaround. I was able to confirm the described behavior (finally) and noticed that the performance increased with the suggested agent config. We are looking into this with priority.
Thank you for all for your help! Ran~
Node profiler output comparing v2 and v3
V3 Profile
Statistical profiling result from isolate-0x128040000-67002-v8.log, (1481 ticks, 12 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
64 4.3% /usr/lib/system/libsystem_malloc.dylib
17 1.1% /usr/lib/system/libsystem_pthread.dylib
11 0.7% /usr/lib/system/libsystem_c.dylib
5 0.3% /usr/lib/system/libsystem_platform.dylib
4 0.3% /usr/lib/libc++.1.dylib
1 0.1% /usr/lib/system/libsystem_kernel.dylib
1 0.1% /usr/lib/libobjc.A.dylib
1 0.1% /usr/lib/libc++abi.dylib
[JavaScript]:
ticks total nonlib name
1 0.1% 0.1% RegExp: ^((?:(?:[0-9a-fA-F]{1,4}):){7}(?:(?:[0-9a-fA-F]{1,4})|:)|(?:(?:[0-9a-fA-F]{1,4}):){6}(?:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|:(?:[0-9a-fA-F]{1,4})|:)|(?:(?:[0-9a-fA-F]{1,4}):){5}(?::((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,2}|:)|(?:(?:[0-9a-fA-F]{1,4}):){4}(?:(:(?:[0-9a-fA-F]{1,4})){0,1}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,3}|:)|(?:(?:[0-9a-fA-F]{1,4}):){3}(?:(:(?:[0-9a-fA-F]{1,4})){0,2}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,4}|:)|(?:(?:[0-9a-fA-F]{1,4}):){2}(?:(:(?:[0-9a-fA-F]{1,4})){0,3}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,5}|:)|(?:(?:[0-9a-fA-F]{1,4}):){1}(?:(:(?:[0-9a-fA-F]{1,4})){0,4}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,6}|:)|(?::((?::(?:[0-9a-fA-F]{1,4})){0,5}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(?::(?:[0-9a-fA-F]{1,4})){1,7}|:)))(%[0-9a-zA-Z-.:]{1,})?$
1 0.1% 0.1% RegExp: (^|\\|\/)((\.|%2e)(\.|%2e)?|(n|%6e|%4e)(o|%6f|%4f)(d|%64|%44)(e|%65|%45)(_|%5f)(m|%6d|%4d)(o|%6f|%4f)(d|%64|%44)(u|%75|%55)(l|%6c|%4c)(e|%65|%45)(s|%73|%53))?(\\|\/|$)
1 0.1% 0.1% LazyCompile: *resolve node:path:1091:10
1 0.1% 0.1% LazyCompile: *applyInstruction /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/object-mapping.js:65:26
1 0.1% 0.1% LazyCompile: *C node:internal/deps/cjs-module-lexer/dist/lexer:1:1152
1 0.1% 0.1% Function: ^resolveParams /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-endpoint/dist-cjs/adaptors/getEndpointFromInstructions.js:15:23
1 0.1% 0.1% Function: ^processTicksAndRejections node:internal/process/task_queues:67:35
1 0.1% 0.1% Function: ^onFree node:_http_agent:384:18
1 0.1% 0.1% Function: ^nextTick node:internal/process/task_queues:103:18
1 0.1% 0.1% Function: ^isUint8Array node:internal/util/types:13:22
1 0.1% 0.1% Function: ^getEncodingOps node:buffer:688:24
1 0.1% 0.1% Function: ^evaluateRules /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/util-endpoints/dist-cjs/utils/evaluateRules.js:8:23
1 0.1% 0.1% Function: ^emitAfterScript node:internal/async_hooks:517:25
1 0.1% 0.1% Function: ^dirname node:path:1275:10
1 0.1% 0.1% Function: ^createSocket node:_http_agent:319:53
1 0.1% 0.1% Function: ^<anonymous> node:internal/validators:138:40
[C++]:
ticks total nonlib name
725 49.0% 52.7% T node::contextify::ContextifyScript::~ContextifyScript()
350 23.6% 25.4% T _posix_spawnattr_setflags
87 5.9% 6.3% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
52 3.5% 3.8% T node::builtins::BuiltinLoader::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
26 1.8% 1.9% T _sigprocmask
17 1.1% 1.2% T _semaphore_destroy
13 0.9% 0.9% T _mach_port_insert_member
11 0.7% 0.8% t __pthread_cond_check_init_slow
10 0.7% 0.7% T _mach_vm_protect
10 0.7% 0.7% T __kernelrpc_mach_port_move_member_trap
9 0.6% 0.7% T node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
6 0.4% 0.4% T _mach_timebase_info_trap
6 0.4% 0.4% T ___bsdthread_terminate
3 0.2% 0.2% t __os_once_gate_wait
2 0.1% 0.1% t std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char)
2 0.1% 0.1% t node::Environment::StartProfilerIdleNotifier()::$_6::__invoke(uv_check_s*)
2 0.1% 0.1% t __pthread_mutex_firstfit_unlock_slow
2 0.1% 0.1% t __os_nospin_lock_unlock_slow
2 0.1% 0.1% t ___pfz_setup
2 0.1% 0.1% T _qos_class_main
2 0.1% 0.1% T _mach_port_insert_right
2 0.1% 0.1% T __kernelrpc_mach_port_get_refs
1 0.1% 0.1% T node::loader::ModuleWrap::New(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.1% 0.1% T node::InternalCallbackScope::~InternalCallbackScope()
1 0.1% 0.1% T node::Emit(node::Environment*, double, node::AsyncHooks::Fields, v8::Local<v8::Function>)
1 0.1% 0.1% T node::AsyncHooks::push_async_context(double, double, v8::Local<v8::Object>)
1 0.1% 0.1% T _pthread_mutex_init
1 0.1% 0.1% T _mach_port_deallocate
1 0.1% 0.1% T __os_semaphore_create
1 0.1% 0.1% T __kernelrpc_mach_vm_map
[Summary]:
ticks total nonlib name
16 1.1% 1.2% JavaScript
1349 91.1% 98.0% C++
61 4.1% 4.4% GC
104 7.0% Shared libraries
12 0.8% Unaccounted
[C++ entry points]:
ticks cpp total name
567 75.5% 38.3% T node::contextify::ContextifyScript::~ContextifyScript()
87 11.6% 5.9% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
52 6.9% 3.5% T node::builtins::BuiltinLoader::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
14 1.9% 0.9% T _sigprocmask
9 1.2% 0.6% T node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
8 1.1% 0.5% T __kernelrpc_mach_port_move_member_trap
7 0.9% 0.5% T node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&)
2 0.3% 0.1% t std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char)
2 0.3% 0.1% t ___pfz_setup
1 0.1% 0.1% t __os_nospin_lock_unlock_slow
1 0.1% 0.1% T node::loader::ModuleWrap::New(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.1% 0.1% T __kernelrpc_mach_port_get_refs
[Bottom up (heavy) profile]:
Note: percentage shows a share of a particular caller in the total
amount of its parent calls.
Callers occupying less than 1.0% are not shown.
ticks parent name
725 49.0% T node::contextify::ContextifyScript::~ContextifyScript()
124 17.1% Function: ^TLSSocket.getPeerCertificate node:_tls_wrap:999:50
118 95.2% Function: ^onConnectSecure node:_tls_wrap:1531:25
93 78.8% Function: ^emit node:events:460:44
93 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
93 100.0% Function: ^ssl.onhandshakedone node:_tls_wrap:741:27
25 21.2% LazyCompile: *emit node:events:460:44
25 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
25 100.0% Function: ^ssl.onhandshakedone node:_tls_wrap:741:27
6 4.8% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
6 100.0% Function: ^emit node:events:460:44
6 100.0% LazyCompile: ~TLSSocket._finishInit node:_tls_wrap:933:43
6 100.0% Function: ^ssl.onhandshakedone node:_tls_wrap:741:27
59 8.1% Function: ^readSync node:fs:705:18
59 100.0% Function: ^tryReadSync node:fs:444:21
59 100.0% Function: ^readFileSync node:fs:465:22
41 69.5% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
41 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
9 15.3% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
8 88.9% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 11.1% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
9 15.3% Function: ^cjsPreparseModuleExports node:internal/modules/esm/translators:193:34
9 100.0% Function: ^<anonymous> node:internal/modules/esm/translators:232:36
27 3.7% Function: ^SecureContext node:_tls_common:75:23
27 100.0% Function: ^createSecureContext node:_tls_common:99:29
27 100.0% Function: ^connect node:_tls_wrap:1612:35
27 100.0% Function: ^createConnection node:https:118:26
27 100.0% Function: ^createSocket node:_http_agent:319:53
26 3.6% Function: ^TLSSocket._init node:_tls_wrap:685:37
26 100.0% Function: ^TLSSocket node:_tls_wrap:470:19
26 100.0% Function: ^connect node:_tls_wrap:1612:35
26 100.0% Function: ^createConnection node:https:118:26
26 100.0% Function: ^createSocket node:_http_agent:319:53
22 3.0% Function: ^methodProxy node:_tls_wrap:560:30
21 95.5% Function: ^internalConnect node:net:1003:25
21 100.0% Function: ^defaultTriggerAsyncIdScope node:internal/async_hooks:455:36
21 100.0% Function: ^emitLookup node:net:1293:46
21 100.0% Function: ^onlookup node:dns:105:18
1 4.5% LazyCompile: ~internalConnect node:net:1003:25
1 100.0% Function: ^defaultTriggerAsyncIdScope node:internal/async_hooks:455:36
1 100.0% Function: ^emitLookup node:net:1293:46
1 100.0% LazyCompile: ~onlookup node:dns:105:18
21 2.9% T node::contextify::ContextifyScript::~ContextifyScript()
2 9.5% T node::contextify::ContextifyScript::~ContextifyScript()
1 50.0% Function: ^stat node:internal/modules/cjs/loader:161:14
1 100.0% Function: ^tryFile node:internal/modules/cjs/loader:440:17
1 100.0% Function: ^tryExtensions node:internal/modules/cjs/loader:456:23
1 50.0% Function: ^readPackage node:internal/modules/cjs/loader:335:21
1 100.0% Function: ^readPackageScope node:internal/modules/cjs/loader:377:26
1 100.0% LazyCompile: ~trySelf node:internal/modules/cjs/loader:497:17
2 9.5% Function: ^splitHost node:tls:170:19
2 100.0% Function: ^check node:tls:177:15
2 100.0% Function: ^wildcard node:tls:313:22
2 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
2 9.5% Function: ^processCiphers node:internal/tls/secure-context:95:24
2 100.0% Function: ^configSecureContext node:internal/tls/secure-context:124:29
2 100.0% Function: ^createSecureContext node:_tls_common:99:29
2 100.0% Function: ^connect node:_tls_wrap:1612:35
2 9.5% Function: ^Module._load node:internal/modules/cjs/loader:851:24
2 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
2 100.0% Function: ^require node:internal/modules/cjs/helpers:102:31
1 50.0% Function: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/hash-stream-node/dist-cjs/HashCalculator.js:1:1
1 50.0% Function: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-sso-oidc/dist-cjs/index.js:1:1
2 9.5% Function: ^Module._findPath node:internal/modules/cjs/loader:555:28
2 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
2 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
2 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 4.8% LazyCompile: ~parseRfc7231DateTime /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/date-utils.js:67:30
1 100.0% LazyCompile: ~contents.LastModified /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-s3/dist-cjs/protocols/Aws_restXml.js:4231:13
1 100.0% Function: ^applyInstruction /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/object-mapping.js:65:26
1 100.0% Function: ^map /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/object-mapping.js:4:13
1 4.8% LazyCompile: ~getProfileData /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/shared-ini-file-loader/dist-cjs/getProfileData.js:5:24
1 4.8% LazyCompile: *callFunction /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/util-endpoints/dist-cjs/utils/callFunction.js:7:22
1 100.0% Function: ^evaluateCondition /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/util-endpoints/dist-cjs/utils/evaluateCondition.js:7:27
1 100.0% Function: ^evaluateConditions /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/util-endpoints/dist-cjs/utils/evaluateConditions.js:6:28
1 100.0% Function: ^evaluateEndpointRule /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/util-endpoints/dist-cjs/utils/evaluateEndpointRule.js:9:30
1 4.8% Function: ~<anonymous> node:internal/net:1:1
1 100.0% Function: ~<anonymous> node:internal/dns/utils:1:1
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 4.8% Function: ^realpathSync node:fs:2474:22
1 100.0% Function: ^toRealPath node:internal/modules/cjs/loader:449:20
1 100.0% Function: ^tryFile node:internal/modules/cjs/loader:440:17
1 100.0% Function: ^tryExtensions node:internal/modules/cjs/loader:456:23
1 4.8% Function: ^readPackage node:internal/modules/cjs/loader:335:21
1 100.0% Function: ^readPackageScope node:internal/modules/cjs/loader:377:26
1 100.0% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 4.8% Function: ^getOwn node:internal/bootstrap/loaders:188:16
1 100.0% Function: ^syncExports node:internal/bootstrap/loaders:307:14
1 100.0% LazyCompile: ~<anonymous> node:internal/bootstrap/loaders:293:15
1 100.0% T node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.8% Function: ^getMiddlewareList /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-stack/dist-cjs/MiddlewareStack.js:69:31
1 100.0% Function: ^resolve /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-stack/dist-cjs/MiddlewareStack.js:202:18
1 100.0% Function: ^resolveMiddleware /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-s3/dist-cjs/commands/GetObjectCommand.js:30:22
1 100.0% Function: ^send /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/client.js:10:9
1 4.8% Function: ^createCanonicalRequest /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/signature-v4/dist-cjs/SignatureV4.js:110:27
1 100.0% Function: ^signRequest /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/signature-v4/dist-cjs/SignatureV4.js:86:22
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 4.8% Function: ^checkServerIdentity node:tls:280:59
1 100.0% Function: ^onConnectSecure node:_tls_wrap:1531:25
1 100.0% Function: ^emit node:events:460:44
1 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
1 4.8% Function: ^check node:tls:177:15
1 100.0% Function: ^wildcard node:tls:313:22
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% Function: ^checkServerIdentity node:tls:280:59
21 2.9% Function: ^TLSSocket._start node:_tls_wrap:962:38
21 100.0% Function: ^onceWrapper node:events:622:21
20 95.2% Function: ^emit node:events:460:44
20 100.0% Function: ^afterConnect node:net:1440:22
1 4.8% LazyCompile: *emit node:events:460:44
1 100.0% Function: ^afterConnect node:net:1440:22
16 2.2% Function: ^TLSSocket.setSession node:_tls_wrap:993:42
16 100.0% Function: ^connect node:_tls_wrap:1612:35
16 100.0% Function: ^createConnection node:https:118:26
16 100.0% Function: ^createSocket node:_http_agent:319:53
16 100.0% Function: ^removeSocket node:_http_agent:433:53
14 1.9% LazyCompile: ~configSecureContext node:internal/tls/secure-context:124:29
14 100.0% LazyCompile: ~createSecureContext node:_tls_common:99:29
14 100.0% LazyCompile: ~connect node:_tls_wrap:1612:35
14 100.0% LazyCompile: ~createConnection node:https:118:26
14 100.0% LazyCompile: ~createSocket node:_http_agent:319:53
13 1.8% Function: ^done node:_tls_wrap:579:16
9 1.2% Function: ^openSync node:fs:591:18
9 100.0% Function: ^readFileSync node:fs:465:22
7 77.8% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
7 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
7 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 11.1% LazyCompile: ~Module._extensions..json node:internal/modules/cjs/loader:1277:39
1 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 11.1% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% LazyCompile: ~Module._load node:internal/modules/cjs/loader:851:24
8 1.1% LazyCompile: ~TLSSocket.getPeerCertificate node:_tls_wrap:999:50
8 100.0% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
8 100.0% Function: ^emit node:events:460:44
8 100.0% LazyCompile: ~TLSSocket._finishInit node:_tls_wrap:933:43
8 100.0% LazyCompile: ~ssl.onhandshakedone node:_tls_wrap:741:27
350 23.6% T _posix_spawnattr_setflags
87 5.9% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
83 95.4% Function: ^internalCompileFunction node:internal/vm:30:33
65 78.3% Function: ^wrapSafe node:internal/modules/cjs/loader:1117:18
65 100.0% Function: ^Module._compile node:internal/modules/cjs/loader:1173:37
65 100.0% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
65 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
18 21.7% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1117:18
16 88.9% Function: ^Module._compile node:internal/modules/cjs/loader:1173:37
16 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
16 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
2 11.1% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
2 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
2 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
4 4.6% LazyCompile: ~internalCompileFunction node:internal/vm:30:33
4 100.0% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1117:18
4 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
4 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
4 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
64 4.3% /usr/lib/system/libsystem_malloc.dylib
2 3.1% T node::contextify::ContextifyScript::~ContextifyScript()
1 50.0% LazyCompile: ~getMiddlewareList /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-stack/dist-cjs/MiddlewareStack.js:69:31
1 100.0% LazyCompile: ~resolve /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-stack/dist-cjs/MiddlewareStack.js:202:18
1 100.0% LazyCompile: ~resolveMiddleware /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-s3/dist-cjs/commands/GetObjectCommand.js:30:22
1 100.0% LazyCompile: ~send /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/client.js:10:9
1 50.0% Function: ^Module._findPath node:internal/modules/cjs/loader:555:28
1 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 1.6% LazyCompile: ~parserOnIncomingClient node:_http_client:607:32
1 100.0% LazyCompile: ~parserOnHeadersComplete node:_http_common:72:33
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% LazyCompile: ~socketOnData node:_http_client:529:22
1 100.0% Function: ^emit node:events:460:44
1 1.6% LazyCompile: ~getDefaultRoleAssumer /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-sts/dist-cjs/defaultRoleAssumers.js:19:31
1 100.0% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-sts/dist-cjs/defaultRoleAssumers.js:23:57
1 100.0% LazyCompile: ~resolveAwsAuthConfig /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-signing/dist-cjs/configurations.js:8:30
1 100.0% LazyCompile: ~S3Client /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-s3/dist-cjs/S3Client.js:20:16
1 100.0% LazyCompile: ~run file:///Users/rvaknin/test_folder/3560a/sample.js:44:19
1 1.6% LazyCompile: ~_finish node:_http_client:369:51
1 100.0% Function: ^_flush node:_http_outgoing:1077:51
1 100.0% LazyCompile: ~onSocketNT node:_http_client:866:20
1 100.0% Function: ^processTicksAndRejections node:internal/process/task_queues:67:35
1 1.6% LazyCompile: ~Module._extensions..json node:internal/modules/cjs/loader:1277:39
1 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 100.0% Function: ^require node:internal/modules/cjs/helpers:102:31
1 1.6% LazyCompile: ~<anonymous> node:internal/validators:288:39
1 100.0% LazyCompile: ~internalCompileFunction node:internal/vm:30:33
1 100.0% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1117:18
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 1.6% Function: ^createConnection node:https:118:26
1 100.0% Function: ^createSocket node:_http_agent:319:53
1 100.0% LazyCompile: ~removeSocket node:_http_agent:433:53
1 100.0% LazyCompile: ~onClose node:_http_agent:390:19
1 100.0% Function: ^emit node:events:460:44
52 3.5% T node::builtins::BuiltinLoader::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
33 63.5% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
28 84.8% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
5 17.9% Function: ~<anonymous> node:http2:1:1
5 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
5 100.0% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
4 14.3% Function: ~<anonymous> node:https:1:1
4 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
4 100.0% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
3 10.7% Function: ~<anonymous> node:tls:1:1
3 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
3 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
2 7.1% Function: ~<anonymous> node:internal/http2/core:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
2 7.1% Function: ~<anonymous> node:internal/child_process:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
2 7.1% Function: ~<anonymous> node:assert:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
2 7.1% Function: ~<anonymous> node:_http_server:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.6% LazyCompile: ~lookupAndConnect node:net:1202:26
1 100.0% LazyCompile: ~Socket.connect node:net:1134:36
1 100.0% LazyCompile: ~connect node:_tls_wrap:1612:35
1 3.6% LazyCompile: ~lazyWebCrypto node:crypto:125:23
1 100.0% LazyCompile: ~get node:crypto:369:8
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 3.6% LazyCompile: ~lazyLoadStreams node:fs:2907:25
1 100.0% LazyCompile: ~get ReadStream node:fs:3050:17
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 3.6% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 3.6% LazyCompile: ~initCJSParse node:internal/modules/esm/translators:58:28
1 100.0% LazyCompile: ~commonjsStrategy node:internal/modules/esm/translators:147:60
1 100.0% LazyCompile: ~moduleProvider node:internal/modules/esm/loader:452:28
1 3.6% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:45:35
1 100.0% LazyCompile: ~getStderr node:internal/bootstrap/switches/is_main_thread:168:19
1 100.0% LazyCompile: ~refresh node:internal/util/colors:10:10
1 3.6% Function: ~<anonymous> node:internal/http2/compat:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.6% Function: ~<anonymous> node:child_process:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
5 15.2% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
4 80.0% Function: ^loadBuiltinModule node:internal/modules/cjs/helpers:45:27
4 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
4 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 20.0% LazyCompile: ~loadBuiltinModule node:internal/modules/cjs/helpers:45:27
1 100.0% LazyCompile: ~builtinStrategy node:internal/modules/esm/translators:253:58
1 100.0% LazyCompile: ~moduleProvider node:internal/modules/esm/loader:452:28
3 5.8% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
3 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
3 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
3 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
3 5.8% Function: ~<anonymous> node:internal/modules/esm/fetch_module:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/get_format:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
3 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
2 3.8% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
2 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
2 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
2 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
2 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
2 3.8% Function: ~<anonymous> node:internal/process/esm_loader:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
2 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
2 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
2 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
2 3.8% Function: ~<anonymous> node:internal/modules/esm/load:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
2 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
2 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
2 3.8% Function: ~<anonymous> node:internal/fs/promises:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/esm/load:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
2 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 1.9% LazyCompile: ~initializeSourceMapsHandlers node:internal/process/pre_execution:596:38
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 1.9% LazyCompile: ~get BlockList node:net:2228:16
1 100.0% Function: ~<anonymous> node:internal/modules/esm/fetch_module:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/get_format:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 1.9% Function: ~<anonymous> node:internal/readline/interface:1:1
1 100.0% Function: ~<anonymous> node:internal/fs/promises:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/load:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 1.9% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 1.9% Function: ~<anonymous> node:internal/main/run_main_module:1:1
26 1.8% T _sigprocmask
2 7.7% Function: ^emit node:events:460:44
1 50.0% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
1 100.0% Function: ^emit node:events:460:44
1 100.0% LazyCompile: ~TLSSocket._finishInit node:_tls_wrap:933:43
1 100.0% LazyCompile: ~ssl.onhandshakedone node:_tls_wrap:741:27
1 50.0% LazyCompile: ~<anonymous> node:net:318:24
1 100.0% LazyCompile: ~done node:_tls_wrap:579:16
1 3.8% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% LazyCompile: ~socketOnData node:_http_client:529:22
1 100.0% Function: ^emit node:events:460:44
1 100.0% LazyCompile: ~addChunk node:internal/streams/readable:312:18
1 100.0% LazyCompile: ~readableAddChunk node:internal/streams/readable:242:26
1 3.8% LazyCompile: ~resolveParams /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-endpoint/dist-cjs/adaptors/getEndpointFromInstructions.js:15:23
1 100.0% LazyCompile: ~getEndpointFromInstructions /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-endpoint/dist-cjs/adaptors/getEndpointFromInstructions.js:6:37
1 100.0% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-endpoint/dist-cjs/endpointMiddleware.js:6:31
1 100.0% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-ssec/dist-cjs/index.js:5:22
1 100.0% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/validate-bucket-name.js:6:22
1 3.8% LazyCompile: ~push node:internal/fixed_queue:99:7
1 100.0% LazyCompile: ~nextTick node:internal/process/task_queues:103:18
1 100.0% LazyCompile: ~TLSSocket node:_tls_wrap:470:19
1 100.0% LazyCompile: ~connect node:_tls_wrap:1612:35
1 100.0% LazyCompile: ~createConnection node:https:118:26
1 3.8% LazyCompile: ~processHeader node:_http_outgoing:570:23
1 100.0% LazyCompile: ~_storeHeader node:_http_outgoing:439:22
1 100.0% LazyCompile: ~_implicitHeader node:_http_client:396:67
1 100.0% LazyCompile: ~end node:_http_outgoing:972:45
1 100.0% LazyCompile: ~writeBody /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/node-http-handler/dist-cjs/write-request-body.js:17:19
1 3.8% LazyCompile: ~parserOnHeadersComplete node:_http_common:72:33
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% LazyCompile: ~socketOnData node:_http_client:529:22
1 100.0% Function: ^emit node:events:460:44
1 100.0% Function: ^addChunk node:internal/streams/readable:312:18
1 3.8% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
1 100.0% Function: ^emit node:events:460:44
1 100.0% LazyCompile: ~TLSSocket._finishInit node:_tls_wrap:933:43
1 100.0% Function: ^ssl.onhandshakedone node:_tls_wrap:741:27
1 3.8% LazyCompile: ~internalConnect node:net:1003:25
1 100.0% Function: ^defaultTriggerAsyncIdScope node:internal/async_hooks:455:36
1 100.0% LazyCompile: ~emitLookup node:net:1293:46
1 100.0% LazyCompile: ~onlookup node:dns:105:18
1 3.8% LazyCompile: ~formatValue node:internal/util/inspect:766:21
1 100.0% LazyCompile: ~inspect node:internal/util/inspect:310:17
1 100.0% LazyCompile: ~formatWithOptionsInternal node:internal/util/inspect:2154:35
1 100.0% LazyCompile: ~formatWithOptions node:internal/util/inspect:2133:27
1 100.0% LazyCompile: ~value node:internal/console/constructor:337:20
1 3.8% LazyCompile: ~finishMaybe node:internal/streams/writable:718:21
1 100.0% LazyCompile: ~Writable.end node:internal/streams/writable:597:34
1 100.0% LazyCompile: ~Socket.end node:net:696:32
1 100.0% LazyCompile: ~endWritableNT node:internal/streams/readable:1381:23
1 100.0% Function: ^processTicksAndRejections node:internal/process/task_queues:67:35
1 3.8% LazyCompile: ~close node:internal/fs/promises:216:11
1 100.0% LazyCompile: ~<anonymous> node:internal/fs/promises:356:5
1 3.8% Function: ^B node:internal/deps/cjs-module-lexer/dist/lexer:1:824
1 100.0% LazyCompile: ~parse node:internal/deps/cjs-module-lexer/dist/lexer:1:131
1 100.0% LazyCompile: ~cjsPreparseModuleExports node:internal/modules/esm/translators:193:34
1 100.0% LazyCompile: ~<anonymous> node:internal/modules/esm/translators:232:36
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 3.8% Function: ^<anonymous> node:internal/validators:419:42
1 100.0% Function: ^internalCompileFunction node:internal/vm:30:33
1 100.0% Function: ^wrapSafe node:internal/modules/cjs/loader:1117:18
1 100.0% Function: ^Module._compile node:internal/modules/cjs/loader:1173:37
1 100.0% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
17 1.1% T _semaphore_destroy
17 1.1% /usr/lib/system/libsystem_pthread.dylib
2 11.8% LazyCompile: ~value node:internal/console/constructor:337:20
2 100.0% LazyCompile: ~log node:internal/console/constructor:376:6
2 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
2 100.0% LazyCompile: ~run file:///Users/rvaknin/test_folder/3560a/sample.js:44:19
2 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 5.9% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% LazyCompile: ~primordials.SafePromiseAllReturnArrayLike node:internal/per_context/primordials:494:45
1 100.0% LazyCompile: ~import node:internal/modules/esm/loader:509:15
1 100.0% LazyCompile: ~<anonymous> node:internal/modules/run_main:55:29
1 100.0% LazyCompile: ~loadESM node:internal/process/esm_loader:88:41
1 5.9% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:449:20
1 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:555:28
1 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:74:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 5.9% LazyCompile: ~setTimeout node:_http_client:930:57
1 100.0% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/node-http-handler/dist-cjs/node-http-handler.js:50:28
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% LazyCompile: ~handle /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/node-http-handler/dist-cjs/node-http-handler.js:46:17
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 5.9% LazyCompile: ~realpathSync node:fs:2474:22
1 100.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:449:20
1 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:555:28
1 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:74:31
1 5.9% LazyCompile: ~readFileHandle node:internal/fs/promises:426:30
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 5.9% LazyCompile: ~patchProcessObject node:internal/process/pre_execution:134:28
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 5.9% LazyCompile: ~defaultResolve node:internal/modules/esm/resolve:1063:30
1 100.0% LazyCompile: ~ObjectDefineProperty.__proto__ node:internal/modules/esm/loader:148:5
1 100.0% LazyCompile: ~resolve node:internal/modules/esm/loader:789:16
1 100.0% LazyCompile: ~getModuleJob node:internal/modules/esm/loader:410:21
1 100.0% LazyCompile: ~import node:internal/modules/esm/loader:509:15
1 5.9% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:45:35
1 100.0% LazyCompile: ~getStderr node:internal/bootstrap/switches/is_main_thread:168:19
1 100.0% LazyCompile: ~refresh node:internal/util/colors:10:10
1 100.0% Function: ~<anonymous> node:internal/util/colors:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 5.9% LazyCompile: ~ReadableState node:internal/streams/readable:83:23
1 100.0% LazyCompile: ~Readable node:internal/streams/readable:186:18
1 100.0% LazyCompile: ~Duplex node:internal/streams/duplex:54:16
1 100.0% LazyCompile: ~Socket node:net:336:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 5.9% LazyCompile: ~Duplex node:internal/streams/duplex:54:16
1 100.0% LazyCompile: ~Socket node:net:336:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:45:35
1 100.0% LazyCompile: ~getStderr node:internal/bootstrap/switches/is_main_thread:168:19
1 5.9% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 5.9% Function: ~<anonymous> node:internal/fs/promises:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/load:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
V2 Profile
Statistical profiling result from isolate-0x130040000-75387-v8.log, (698 ticks, 5 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
17 2.4% /usr/lib/system/libsystem_malloc.dylib
14 2.0% /usr/lib/system/libsystem_pthread.dylib
14 2.0% /usr/lib/system/libsystem_c.dylib
6 0.9% /usr/lib/libc++.1.dylib
3 0.4% /usr/lib/system/libsystem_kernel.dylib
1 0.1% /usr/lib/libc++abi.dylib
[JavaScript]:
ticks total nonlib name
3 0.4% 0.5% LazyCompile: *normalizeString node:path:66:25
2 0.3% 0.3% LazyCompile: *resolve node:path:1091:10
2 0.3% 0.3% LazyCompile: *Module._findPath node:internal/modules/cjs/loader:555:28
2 0.3% 0.3% Function: ^emit node:events:460:44
2 0.3% 0.3% Function: *wasm-function[15]
1 0.1% 0.2% LazyCompile: *dirname node:path:1275:10
1 0.1% 0.2% LazyCompile: *Module._resolveLookupPaths node:internal/modules/cjs/loader:753:38
1 0.1% 0.2% LazyCompile: *Module._nodeModulePaths node:internal/modules/cjs/loader:715:37
1 0.1% 0.2% LazyCompile: *C node:internal/deps/cjs-module-lexer/dist/lexer:1:1152
1 0.1% 0.2% Function: wasm-function[38]
1 0.1% 0.2% Function: ^trySelf node:internal/modules/cjs/loader:497:17
1 0.1% 0.2% Function: ^popAsyncContext node:internal/async_hooks:553:25
1 0.1% 0.2% Function: ^parseTimestamp /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/util.js:343:44
1 0.1% 0.2% Function: ^onwrite node:internal/streams/writable:428:17
1 0.1% 0.2% Function: ^get node:_http_outgoing:173:6
1 0.1% 0.2% Function: ^emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:680:27
1 0.1% 0.2% Function: ^alignPool node:buffer:167:19
1 0.1% 0.2% Function: ^_writeRaw node:_http_outgoing:390:19
1 0.1% 0.2% Function: ^_unrefTimer node:net:484:52
1 0.1% 0.2% Function: ^C node:internal/deps/cjs-module-lexer/dist/lexer:1:1152
1 0.1% 0.2% Function: ^<anonymous> node:internal/validators:419:42
[C++]:
ticks total nonlib name
244 35.0% 37.9% T node::contextify::ContextifyScript::~ContextifyScript()
143 20.5% 22.2% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
121 17.3% 18.8% T _posix_spawnattr_setflags
49 7.0% 7.6% T node::builtins::BuiltinLoader::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
18 2.6% 2.8% T _sigprocmask
6 0.9% 0.9% T __kernelrpc_mach_port_move_member_trap
5 0.7% 0.8% T _task_get_exception_ports
4 0.6% 0.6% T ___bsdthread_terminate
3 0.4% 0.5% t ___pfz_setup
3 0.4% 0.5% T _semaphore_destroy
3 0.4% 0.5% T _mach_timebase_info_trap
2 0.3% 0.3% t std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char)
2 0.3% 0.3% t std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long)
2 0.3% 0.3% T node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
2 0.3% 0.3% T node::AsyncWrap::EmitTraceEventAfter(node::AsyncWrap::ProviderType, double)
1 0.1% 0.2% t void std::__1::__tree_balance_after_insert<std::__1::__tree_node_base<void*>*>(std::__1::__tree_node_base<void*>*, std::__1::__tree_node_base<void*>*)
1 0.1% 0.2% t __os_nospin_lock_lock_slow
1 0.1% 0.2% T _mach_port_insert_right
1 0.1% 0.2% T _mach_port_insert_member
[Summary]:
ticks total nonlib name
27 3.9% 4.2% JavaScript
611 87.5% 95.0% C++
7 1.0% 1.1% GC
55 7.9% Shared libraries
5 0.7% Unaccounted
[C++ entry points]:
ticks cpp total name
226 49.0% 32.4% T node::contextify::ContextifyScript::~ContextifyScript()
143 31.0% 20.5% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
49 10.6% 7.0% T node::builtins::BuiltinLoader::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
15 3.3% 2.1% T _sigprocmask
8 1.7% 1.1% T node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&)
6 1.3% 0.9% T __kernelrpc_mach_port_move_member_trap
5 1.1% 0.7% T _task_get_exception_ports
3 0.7% 0.4% t ___pfz_setup
2 0.4% 0.3% t std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char)
2 0.4% 0.3% T node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.2% 0.1% t void std::__1::__tree_balance_after_insert<std::__1::__tree_node_base<void*>*>(std::__1::__tree_node_base<void*>*, std::__1::__tree_node_base<void*>*)
1 0.2% 0.1% t std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long)
[Bottom up (heavy) profile]:
Note: percentage shows a share of a particular caller in the total
amount of its parent calls.
Callers occupying less than 1.0% are not shown.
ticks parent name
244 35.0% T node::contextify::ContextifyScript::~ContextifyScript()
24 9.8% Function: ^TLSSocket.getPeerCertificate node:_tls_wrap:999:50
20 83.3% Function: ^onConnectSecure node:_tls_wrap:1531:25
20 100.0% Function: ^emit node:events:460:44
20 100.0% Function: ^emit node:domain:478:44
20 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
4 16.7% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
4 100.0% Function: ^emit node:events:460:44
4 100.0% Function: ^emit node:domain:478:44
4 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
21 8.6% Function: ^openSync node:fs:591:18
21 100.0% Function: ^readFileSync node:fs:465:22
18 85.7% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
18 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
18 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
2 9.5% Function: ^cjsPreparseModuleExports node:internal/modules/esm/translators:193:34
2 100.0% Function: ^<anonymous> node:internal/modules/esm/translators:232:36
2 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 4.8% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% LazyCompile: ~Module._load node:internal/modules/cjs/loader:851:24
14 5.7% LazyCompile: ~configSecureContext node:internal/tls/secure-context:124:29
13 92.9% LazyCompile: ~createSecureContext node:_tls_common:99:29
13 100.0% LazyCompile: ~connect node:_tls_wrap:1612:35
13 100.0% LazyCompile: ~createConnection node:https:118:26
13 100.0% LazyCompile: ~createSocket node:_http_agent:319:53
1 7.1% Function: ^createSecureContext node:_tls_common:99:29
1 100.0% Function: ^connect node:_tls_wrap:1612:35
1 100.0% Function: ^createConnection node:https:118:26
1 100.0% Function: ^createSocket node:_http_agent:319:53
13 5.3% T node::contextify::ContextifyScript::~ContextifyScript()
3 23.1% T node::contextify::ContextifyScript::~ContextifyScript()
1 33.3% Function: ^stat node:internal/modules/cjs/loader:161:14
1 100.0% Function: ^tryFile node:internal/modules/cjs/loader:440:17
1 100.0% Function: ^tryExtensions node:internal/modules/cjs/loader:456:23
1 33.3% Function: ^readPackage node:internal/modules/cjs/loader:335:21
1 100.0% Function: ^readPackageScope node:internal/modules/cjs/loader:377:26
1 100.0% Function: ^trySelf node:internal/modules/cjs/loader:497:17
1 33.3% Function: ^<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:113:37
1 100.0% LazyCompile: *each /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/util.js:517:22
1 100.0% Function: ^extractData /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:100:21
2 15.4% LazyCompile: *readPackageScope node:internal/modules/cjs/loader:377:26
1 50.0% Function: ^trySelf node:internal/modules/cjs/loader:497:17
1 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 50.0% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
2 15.4% Function: ^Module._findPath node:internal/modules/cjs/loader:555:28
2 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
2 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
2 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 7.7% LazyCompile: ~isIPv6 node:internal/net:38:16
1 100.0% LazyCompile: ~isIP node:internal/net:45:14
1 100.0% LazyCompile: ~lookupAndConnect node:net:1202:26
1 100.0% LazyCompile: ~Socket.connect node:net:1134:36
1 7.7% LazyCompile: ~generateURI /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:8:21
1 100.0% LazyCompile: ~populateURI /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:62:21
1 100.0% LazyCompile: ~buildRequest /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:90:22
1 100.0% LazyCompile: ~buildRequest /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest_xml.js:28:22
1 7.7% LazyCompile: ~checkIsHttpToken node:_http_common:210:26
1 100.0% LazyCompile: ~<anonymous> node:_http_outgoing:631:44
1 100.0% LazyCompile: ~setHeader node:_http_outgoing:661:57
1 100.0% LazyCompile: ~ClientRequest node:_http_client:134:23
1 7.7% Function: ^readPackage node:internal/modules/cjs/loader:335:21
1 100.0% Function: ^readPackageScope node:internal/modules/cjs/loader:377:26
1 100.0% Function: ^trySelf node:internal/modules/cjs/loader:497:17
1 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
1 7.7% Function: ^getOwn node:internal/bootstrap/loaders:188:16
1 100.0% Function: ^syncExports node:internal/bootstrap/loaders:307:14
1 100.0% LazyCompile: ~<anonymous> node:internal/bootstrap/loaders:293:15
1 100.0% T node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&)
1 7.7% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 100.0% Function: ^require node:internal/modules/cjs/helpers:102:31
6 2.5% LazyCompile: ~TLSSocket.getPeerCertificate node:_tls_wrap:999:50
6 100.0% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
6 100.0% Function: ^emit node:events:460:44
6 100.0% Function: ^emit node:domain:478:44
6 100.0% LazyCompile: ~TLSSocket._finishInit node:_tls_wrap:933:43
5 2.0% LazyCompile: ~done node:_tls_wrap:579:16
5 2.0% Function: ^handleWriteReq node:internal/stream_base_commons:45:24
5 100.0% Function: ^writeGeneric node:internal/stream_base_commons:147:22
5 100.0% Function: ^Socket._writeGeneric node:net:897:42
5 100.0% Function: ^Socket._write node:net:934:35
5 100.0% Function: ^doWrite node:internal/streams/writable:401:17
5 2.0% Function: ^closeSync node:fs:541:19
5 100.0% Function: ^readFileSync node:fs:465:22
3 60.0% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
3 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
3 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
2 40.0% Function: ^cjsPreparseModuleExports node:internal/modules/esm/translators:193:34
2 100.0% Function: ^<anonymous> node:internal/modules/esm/translators:232:36
2 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
4 1.6% Function: ^socketMethodProxy node:_tls_wrap:1030:36
3 75.0% Function: ^onConnectSecure node:_tls_wrap:1531:25
3 100.0% Function: ^emit node:events:460:44
3 100.0% Function: ^emit node:domain:478:44
3 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
1 25.0% LazyCompile: ~onConnectSecure node:_tls_wrap:1531:25
1 100.0% Function: ^emit node:events:460:44
1 100.0% Function: ^emit node:domain:478:44
1 100.0% Function: ^TLSSocket._finishInit node:_tls_wrap:933:43
4 1.6% Function: ^TLSSocket._start node:_tls_wrap:962:38
4 100.0% Function: ^onceWrapper node:events:622:21
4 100.0% Function: ^emit node:events:460:44
4 100.0% Function: ^emit node:domain:478:44
2 50.0% LazyCompile: ~afterConnect node:net:1440:22
2 50.0% Function: ^afterConnect node:net:1440:22
3 1.2% LazyCompile: *readPackageScope node:internal/modules/cjs/loader:377:26
3 100.0% Function: ^trySelf node:internal/modules/cjs/loader:497:17
3 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
3 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
3 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
3 1.2% Function: ^readPackage node:internal/modules/cjs/loader:335:21
2 66.7% Function: ^resolveExports node:internal/modules/cjs/loader:528:24
2 100.0% Function: ^Module._findPath node:internal/modules/cjs/loader:555:28
2 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
2 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 33.3% LazyCompile: *Module._findPath node:internal/modules/cjs/loader:555:28
1 100.0% Function: ^Module._resolveFilename node:internal/modules/cjs/loader:948:35
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
143 20.5% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
141 98.6% Function: ^internalCompileFunction node:internal/vm:30:33
139 98.6% Function: ^wrapSafe node:internal/modules/cjs/loader:1117:18
139 100.0% Function: ^Module._compile node:internal/modules/cjs/loader:1173:37
122 87.8% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
122 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
17 12.2% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
17 100.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
2 1.4% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1117:18
2 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
2 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 50.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
1 50.0% Function: ^Module.load node:internal/modules/cjs/loader:1069:33
2 1.4% LazyCompile: ~internalCompileFunction node:internal/vm:30:33
2 100.0% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1117:18
2 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
2 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
2 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
121 17.3% T _posix_spawnattr_setflags
49 7.0% T node::builtins::BuiltinLoader::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
31 63.3% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
27 87.1% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
5 18.5% Function: ~<anonymous> node:https:1:1
5 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
5 100.0% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
5 18.5% Function: ~<anonymous> node:http2:1:1
5 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
5 100.0% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
2 7.4% Function: ~<anonymous> node:tls:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
2 7.4% Function: ~<anonymous> node:internal/http2/core:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
2 7.4% Function: ~<anonymous> node:child_process:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
2 7.4% Function: ~<anonymous> node:assert:1:1
2 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
2 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.7% LazyCompile: ~lazyWebCrypto node:crypto:125:23
1 100.0% LazyCompile: ~get node:crypto:369:8
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 3.7% LazyCompile: ~lazyLoadStreams node:fs:2907:25
1 100.0% LazyCompile: ~get ReadStream node:fs:3050:17
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 3.7% LazyCompile: ~initCJSParse node:internal/modules/esm/translators:58:28
1 100.0% LazyCompile: ~commonjsStrategy node:internal/modules/esm/translators:147:60
1 100.0% LazyCompile: ~moduleProvider node:internal/modules/esm/loader:452:28
1 3.7% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:45:35
1 100.0% LazyCompile: ~getStderr node:internal/bootstrap/switches/is_main_thread:168:19
1 100.0% LazyCompile: ~refresh node:internal/util/colors:10:10
1 3.7% Function: ~<anonymous> node:internal/http2/compat:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.7% Function: ~<anonymous> node:internal/child_process:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.7% Function: ~<anonymous> node:_tls_common:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.7% Function: ~<anonymous> node:_http_server:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 3.7% Function: ~<anonymous> node:_http_common:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
3 9.7% LazyCompile: ~compileForPublicLoader node:internal/bootstrap/loaders:264:25
3 100.0% Function: ^loadBuiltinModule node:internal/modules/cjs/helpers:45:27
3 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
3 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 3.2% Function: ^compileForPublicLoader node:internal/bootstrap/loaders:264:25
1 100.0% Function: ^loadBuiltinModule node:internal/modules/cjs/helpers:45:27
1 100.0% Function: ^Module._load node:internal/modules/cjs/loader:851:24
1 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
3 6.1% Function: ~<anonymous> node:internal/modules/esm/fetch_module:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/get_format:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
3 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
3 6.1% Function: ~<anonymous> node:internal/fs/promises:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/load:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
3 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
3 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
2 4.1% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
2 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
2 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
2 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
2 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
2 4.1% Function: ~<anonymous> node:internal/process/esm_loader:1:1
2 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
2 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
2 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
2 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 2.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 2.0% LazyCompile: ~initializeSourceMapsHandlers node:internal/process/pre_execution:596:38
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 2.0% Function: ~<anonymous> node:internal/source_map/source_map_cache:1:1
1 100.0% LazyCompile: ~initializeSourceMapsHandlers node:internal/process/pre_execution:596:38
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 2.0% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 2.0% Function: ~<anonymous> node:internal/modules/esm/module_map:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 2.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
1 2.0% Function: ~<anonymous> node:internal/modules/esm/load:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
1 100.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 2.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
18 2.6% T _sigprocmask
1 5.6% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% Function: ^getOwn node:internal/bootstrap/loaders:188:16
1 100.0% Function: ^syncExports node:internal/bootstrap/loaders:307:14
1 100.0% LazyCompile: ~<anonymous> node:internal/bootstrap/loaders:293:15
1 100.0% T node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&)
1 5.6% LazyCompile: ~writeBody /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http/node.js:115:32
1 100.0% Function: ^handleRequest /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http/node.js:12:40
1 100.0% Function: ^executeSend /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/event_listeners.js:448:27
1 100.0% Function: ^SEND /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/event_listeners.js:366:43
1 100.0% Function: ^callListeners /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:85:40
1 5.6% LazyCompile: ~readFileHandle node:internal/fs/promises:426:30
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 5.6% LazyCompile: ~patchProcessObject node:internal/process/pre_execution:134:28
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 5.6% LazyCompile: ~hash /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:176:32
1 100.0% LazyCompile: ~stringToSign /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:108:38
1 100.0% LazyCompile: ~signature /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:97:32
1 100.0% LazyCompile: ~authorization /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:87:40
1 100.0% LazyCompile: ~addAuthorization /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:25:46
1 5.6% LazyCompile: ~createSecureContext node:_tls_common:99:29
1 100.0% LazyCompile: ~connect node:_tls_wrap:1612:35
1 100.0% LazyCompile: ~createConnection node:https:118:26
1 100.0% LazyCompile: ~createSocket node:_http_agent:319:53
1 100.0% LazyCompile: ~addRequest node:_http_agent:248:49
1 5.6% LazyCompile: ~channel node:diagnostics_channel:97:17
1 100.0% Function: ~<anonymous> node:_http_server:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 100.0% Function: ^requireBuiltin node:internal/bootstrap/loaders:356:24
1 100.0% Function: ~<anonymous> node:https:1:1
1 5.6% LazyCompile: ~basename node:path:1306:11
1 100.0% LazyCompile: ~findLongestRegisteredExtension node:internal/modules/cjs/loader:469:40
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% LazyCompile: ~Module._load node:internal/modules/cjs/loader:851:24
1 100.0% LazyCompile: ~Module.require node:internal/modules/cjs/loader:1097:36
1 5.6% LazyCompile: ~_storeHeader node:_http_outgoing:439:22
1 100.0% Function: ^_implicitHeader node:_http_client:396:67
1 100.0% LazyCompile: ~end node:_http_outgoing:972:45
1 100.0% LazyCompile: ~writeBody /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http/node.js:115:32
1 100.0% Function: ^handleRequest /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http/node.js:12:40
1 5.6% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:782:35
1 100.0% Function: ^callListeners /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:85:40
1 100.0% Function: ^emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:74:22
1 100.0% Function: ^emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:680:27
1 100.0% Function: ^transition /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:18:28
1 5.6% Function: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/client-s3/dist-cjs/index.js:1:1
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
1 100.0% LazyCompile: ~Module._load node:internal/modules/cjs/loader:851:24
1 5.6% Function: ^onceWrapper node:events:622:21
1 100.0% Function: ^emit node:events:460:44
1 100.0% Function: ^emit node:domain:478:44
1 100.0% LazyCompile: ~<anonymous> node:net:318:24
1 100.0% LazyCompile: ~done node:_tls_wrap:579:16
1 5.6% Function: ^_implicitHeader node:_http_client:396:67
1 100.0% Function: ^end node:_http_outgoing:972:45
1 100.0% Function: ^writeBody /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http/node.js:115:32
1 100.0% Function: ^handleRequest /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http/node.js:12:40
1 100.0% Function: ^executeSend /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/event_listeners.js:448:27
1 5.6% Function: ^B node:internal/deps/cjs-module-lexer/dist/lexer:1:824
1 100.0% LazyCompile: ~parse node:internal/deps/cjs-module-lexer/dist/lexer:1:131
1 100.0% LazyCompile: ~cjsPreparseModuleExports node:internal/modules/esm/translators:193:34
1 100.0% LazyCompile: ~<anonymous> node:internal/modules/esm/translators:232:36
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 5.6% Function: ^<anonymous> node:internal/validators:419:42
1 100.0% Function: ^internalCompileFunction node:internal/vm:30:33
1 100.0% Function: ^wrapSafe node:internal/modules/cjs/loader:1117:18
1 100.0% Function: ^Module._compile node:internal/modules/cjs/loader:1173:37
1 100.0% Function: ^Module._extensions..js node:internal/modules/cjs/loader:1227:37
17 2.4% /usr/lib/system/libsystem_malloc.dylib
1 5.9% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% LazyCompile: ~resolvePackageTargetString node:internal/modules/esm/resolve:412:36
1 100.0% LazyCompile: ~resolvePackageTarget node:internal/modules/esm/resolve:519:30
1 100.0% LazyCompile: ~resolvePackageTarget node:internal/modules/esm/resolve:519:30
1 100.0% LazyCompile: ~packageExportsResolve node:internal/modules/esm/resolve:625:31
1 5.9% LazyCompile: ~internalCompileFunction node:internal/vm:30:33
1 100.0% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1117:18
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1227:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:1069:33
1 5.9% LazyCompile: ~callListeners /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:85:40
1 100.0% LazyCompile: ~emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:74:22
1 100.0% LazyCompile: ~emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:680:27
1 100.0% LazyCompile: ~transition /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:18:28
1 100.0% LazyCompile: ~runTo /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/state_machine.js:6:54
1 5.9% LazyCompile: ~ObjectDefineProperty.__proto__ node:internal/modules/esm/loader:148:5
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 5.9% LazyCompile: ~Module._load node:internal/modules/cjs/loader:851:24
1 100.0% Function: ^Module.require node:internal/modules/cjs/loader:1097:36
1 100.0% Function: ^require node:internal/modules/cjs/helpers:102:31
1 100.0% Function: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/@aws-sdk/smithy-client/dist-cjs/index.js:1:1
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1173:37
14 2.0% /usr/lib/system/libsystem_pthread.dylib
1 7.1% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:449:20
1 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:555:28
1 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:74:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 7.1% LazyCompile: ~setupTraceCategoryState node:internal/process/pre_execution:382:33
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 7.1% LazyCompile: ~realpathSync node:fs:2474:22
1 100.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:449:20
1 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:555:28
1 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:74:31
1 7.1% LazyCompile: ~onParseError node:internal/url:564:22
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% Function: ^URL node:internal/url:637:14
1 100.0% LazyCompile: ~defaultResolve node:internal/modules/esm/resolve:1063:30
1 100.0% LazyCompile: ~ObjectDefineProperty.__proto__ node:internal/modules/esm/loader:148:5
1 7.1% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:45:35
1 100.0% LazyCompile: ~getStderr node:internal/bootstrap/switches/is_main_thread:168:19
1 100.0% LazyCompile: ~refresh node:internal/util/colors:10:10
1 100.0% Function: ~<anonymous> node:internal/util/colors:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:319:27
1 7.1% LazyCompile: ~createHmac node:crypto:164:20
1 100.0% LazyCompile: ~hmac /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/util.js:431:24
1 100.0% LazyCompile: ~getSigningKey /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4_credentials.js:54:40
1 100.0% LazyCompile: ~signature /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:97:32
1 100.0% LazyCompile: ~authorization /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:87:40
1 7.1% LazyCompile: ~TLSSocket._init node:_tls_wrap:685:37
1 100.0% Function: ^TLSSocket node:_tls_wrap:470:19
1 100.0% Function: ^connect node:_tls_wrap:1612:35
1 100.0% Function: ^createConnection node:https:118:26
1 100.0% Function: ^createSocket node:_http_agent:319:53
1 7.1% LazyCompile: ~Duplex node:internal/streams/duplex:54:16
1 100.0% LazyCompile: ~Socket node:net:336:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:45:35
1 100.0% LazyCompile: ~getStderr node:internal/bootstrap/switches/is_main_thread:168:19
1 7.1% LazyCompile: ~<anonymous> node:internal/validators:247:3
1 100.0% LazyCompile: ~SocketAddress node:internal/socketaddress:47:14
1 100.0% LazyCompile: ~addAddress node:internal/blocklist:60:13
1 100.0% Function: ~<anonymous> node:internal/modules/esm/fetch_module:1:1
1 100.0% Function: ~<anonymous> node:internal/modules/esm/get_format:1:1
1 7.1% LazyCompile: ~<anonymous> node:_http_client:950:34
1 100.0% Function: ^onceWrapper node:events:622:21
1 100.0% Function: ^emit node:events:460:44
1 100.0% Function: ^emit node:domain:478:44
1 100.0% LazyCompile: ~afterConnect node:net:1440:22
1 7.1% Function: ^emit node:domain:478:44
14 2.0% /usr/lib/system/libsystem_c.dylib
2 14.3% LazyCompile: ~value node:internal/console/constructor:346:20
2 100.0% LazyCompile: ~warn node:internal/console/constructor:381:7
2 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
2 100.0% LazyCompile: ~writeOut node:internal/process/warning:56:18
2 100.0% LazyCompile: ~onWarning node:internal/process/warning:92:19
1 7.1% LazyCompile: ~readPackageScope node:internal/modules/cjs/loader:377:26
1 100.0% LazyCompile: ~shouldUseESMLoader node:internal/modules/run_main:30:28
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:74:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 7.1% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 7.1% LazyCompile: ~patchProcessObject node:internal/process/pre_execution:134:28
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 7.1% LazyCompile: ~parse node:url:175:37
1 100.0% LazyCompile: ~urlParse node:url:143:18
1 100.0% LazyCompile: ~urlParse /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/util.js:59:30
1 100.0% LazyCompile: ~Endpoint /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/http.js:43:33
1 100.0% LazyCompile: ~setEndpoint /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/service.js:668:36
1 7.1% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:146:19
1 100.0% T node::contextify::ContextifyScript::~ContextifyScript()
1 100.0% Function: ^getOwn node:internal/bootstrap/loaders:188:16
1 100.0% Function: ^syncExports node:internal/bootstrap/loaders:307:14
1 100.0% LazyCompile: ~<anonymous> node:internal/bootstrap/loaders:293:15
1 7.1% LazyCompile: ~SET_CONTENT_LENGTH /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/event_listeners.js:219:72
1 100.0% LazyCompile: ~callListeners /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:85:40
1 100.0% LazyCompile: ~emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:74:22
1 100.0% LazyCompile: ~emit /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:680:27
1 100.0% LazyCompile: ~transition /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/request.js:18:28
1 7.1% LazyCompile: ~ReadableState node:internal/streams/readable:83:23
1 100.0% LazyCompile: ~Readable node:internal/streams/readable:186:18
1 100.0% LazyCompile: ~Duplex node:internal/streams/duplex:54:16
1 100.0% LazyCompile: ~Socket node:net:336:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 7.1% LazyCompile: ~<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:113:37
1 100.0% LazyCompile: *each /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/util.js:517:22
1 100.0% LazyCompile: ~extractData /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest.js:100:21
1 100.0% LazyCompile: ~extractData /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/protocol/rest_xml.js:65:21
1 100.0% Function: ^callListeners /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/sequential_executor.js:85:40
1 7.1% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/process/pre_execution:557:29
1 100.0% LazyCompile: ~setupUserModules node:internal/process/pre_execution:120:26
1 100.0% LazyCompile: ~prepareExecution node:internal/process/pre_execution:51:26
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/process/pre_execution:35:36
1 7.1% Function: ^processTicksAndRejections node:internal/process/task_queues:67:35
1 7.1% Function: ^iso8601 /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/util.js:295:30
1 100.0% Function: ^addAuthorization /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/signers/v4.js:25:46
1 100.0% Function: ^<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/event_listeners.js:307:48
1 100.0% Function: ^finish /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/config.js:395:20
1 100.0% Function: ^<anonymous> /Users/rvaknin/test_folder/3560a/node_modules/aws-sdk/lib/config.js:408:36
Github repo to reproduce issue
We are seeing a similar problem and I don't think this is much of an edge case.
We are pretty much just piping the files from s3 to the client
const commandResult = await client.send(command);
commandResult.Body.pipe(response);
And if there is a file that takes like a minute to download (slower devices/slower internet) If you download more an more from the server on different clients we see the download go slower and slower until it stops, this is even with the work around.
I may be misunderstanding how to do this, but a similar flow worked great from v2.
https://github.com/aws/aws-sdk-js-v3/issues/3560#issuecomment-1484140333 the https.Agent configuration above is not exactly a workaround, it is the correct and recommended way to increase the socket pool.
I will submit a change that begins the socket timeout countdown before the socket event as requested in https://github.com/aws/aws-sdk-js-v3/issues/3722 that may be related to @ToyboxZach 's problem.
@kuhe @RanVaknin Workaround not working for the parallel getObject + upload requests, after around 100 items fetched/uploaded connection hangs concurrency 20-50 S3 client initialized on lambda start Basically works once every ~20 times correctly
Single client for both download and upload not really working
the only option that somehow works consistently is to create 2 separate clients for the actual upload and download:
import {NodeHttpHandler} from '@smithy/node-http-handler';
import {Agent} from 'node:https';
const s3download = new S3({
region: process.env.AWS_REGION,
logger: console,
forcePathStyle: true,
requestHandler: new NodeHttpHandler({
httpsAgent: new Agent({
timeout: 5000,
maxSockets: 1000, // default 50
// keepAlive is a default from AWS SDK. We want to preserve this for
// performance reasons.
keepAlive: true,
keepAliveMsecs: 1000, // default unset,
}),
connectionTimeout: 1000,
requestTimeout: 5000, // default 0
}),
});
const s3upload = new S3({
region: process.env.AWS_REGION,
logger: console,
forcePathStyle: true,
requestHandler: new NodeHttpHandler({
httpsAgent: new Agent({
maxSockets: 1000, // default 50
keepAlive: false,
}),
connectionTimeout: 1000,
requestTimeout: 5000, // default 0
}),
});
And im kinda sure that this will also fail if enough files are supplied
Any updates on this issue? We are experiencing the issue on our side too. Comparing V2 request breakdown and V3 request breakdown side by side made by the datadog tracer. Made all suggestions about sockets from above. To explain the images below: V3 requests consists of the weird HTTP EC2META requests plus the actual S3 request. V2 has only the actual S3 request.
V2
V3
@1nstinct you provided a flame graph, but you should provide a minimal reproduction with code. Are you instantiating a client per request?
@kuhe yes, every request I instantiating a new client and destroying it after.
function read() {
return [
(req, res, next) => {
const modelId = 'model_id';
const model = req.params[modelId];
const client = new AWS.S3({
"region": "us-west-2",
"useAccelerateEndpoint": true,
"signatureVersion": "v4"
});
const begin = Date.now();
req.s3Params = {
Bucket: model.bucket,
Key: `${model.key}/${req.params[0]}`,
ResponseContentType: "application/octet-stream",
};
client.getObject(req.s3Params)
.createReadStream()
.on('error', err => {
if (err.statusCode === 404) {
return next(boom.notFound());
}
// TODO: Better error handling
next(err);
})
.on('end', () => {
// eslint-disable-next-line
if (DEBUG) console.log(`============== V2 file ${req.params[0]} download time: ${Date.now() - begin} ms`);
})
.pipe(res);
}
];
}
function readV3() {
return [
async (req, res, next) => {
try {
const modelId = 'model_id';
const model = req.params[modelId];
let instanceCredentials;
if (process.env.NODE_ENV === 'localhost') {
instanceCredentials = fromIni({
maxRetries: 5, // The maximum number of times any HTTP connections should be retried
timeout: 100, // The connection timeout (in milliseconds) to apply to any remote requests
});
} else {
instanceCredentials = fromInstanceMetadata({
maxRetries: 5, // The maximum number of times any HTTP connections should be retried
timeout: 100, // The connection timeout (in milliseconds) to apply to any remote requests
});
}
const serviceConfig = {
region: "us-west-2",
useAccelerateEndpoint: true,
// Use a custom request handler so that we can adjust the HTTPS Agent and
// socket behavior.
requestHandler: new NodeHttpHandler({
httpsAgent: new https.Agent({
maxSockets: 500, // avoid hanging because of all sockets are in use
// keepAlive is a default from AWS SDK. We want to preserve this for
// performance reasons.
keepAlive: true,
keepAliveMsecs: 1000,
}),
socketTimeout: 5000,
}),
credentials: instanceCredentials
};
const begin = Date.now();
req.s3Params = {
Bucket: model.bucket,
Key: `${model.key}/${req.params[0]}`,
ResponseContentType: "application/octet-stream",
};
const command = new GetObjectCommand(req.s3Params);
// new client per request
const client = new S3Client(serviceConfig);
const response = await client.send(command);
res.status(response.Body.statusCode);
response.Body.on('end', () => {
client.destroy();
// eslint-disable-next-line
if (DEBUG) console.log(`============== V3 file ${req.params[0]} download time: ${Date.now() - begin} ms`);
});
response.Body.pipe(res);
} catch (err) {
if (err.name === 'NoSuchKey') {
return next(boom.notFound());
}
// TODO: Better error handling
return next(boom.badRequest(err.message));
}
}
];
}
"dependencies": {
"@aws-sdk/client-s3": "^3.485.0",
"@aws-sdk/credential-providers": "^3.485.0",
"@aws-sdk/node-http-handler": "^3.374.0",
}
node -v v18.16.1
A single file download speed results. No multi thread downloads.
Avoid instantiating the client every request. Doing so causes the credentials to be fetched, in this case from ec2 metadata service.
@kuhe the performance for V3 is close to V2 now. But we can't use this solution because we started getting "socket hang up" error I believe because V3 client is global variable now - we do not initialize it every request.
looks like it's similar to what this guy reported https://github.com/aws/aws-sdk-js-v3/issues/5561#issuecomment-1850924931
I tried to used these socket configs:
{
"region": "us-west-2",
"maxSockets": 5000,
"keepAliveMsecs": 5000,
"socketTimeout": 120000,
"useAccelerateEndpoint": true
}
{
"region": "us-west-2",
"maxSockets": 500,
"keepAliveMsecs": 1000,
"socketTimeout": 5000,
"useAccelerateEndpoint": true
}
with every config we are getting the error.
I found this issue via a comment on this StackOverflow post, although as far as I can tell the issues are slightly different: https://stackoverflow.com/questions/73256172/nodejs-amazon-aws-sdk-s3-client-stops-working-intermittently
Should I open a new issue for this? I'm not the OP of the SO post, but I've noticed an issue as described there so I wonder if somebody with more insight can tell me if it's related. Every few days, an instance of S3Client just stops working - calling await client.send(new GetObjectCommand({ ... })) does not throw an exception and does not return; it hangs indefinitely. It took me a while to narrow the issue down to this cause.
Edit I found this issue which seems to indicate that yes, it is related.
Been tracking this ticket and just wanted to throw in our experience. We have a node service running in Fargate on ECS that essentially acts as a proxy to images in S3 buckets. It works with streams, reading from the S3 bucket, applying some image transformations and returning the transformed images by writing to a stream (an ExpressJS response). It handles many concurrent requests.
We attempted an upgrade to the AWS SDK v3 and saw a memory leak as well as hanging responses. We'd see the node process completely get hung up and be non-responsive. Log output would would stop and it would then be terminated due to failed health checks since it couldn't respond.
Everything works perfectly fine with the v2 SDK, so we had to revert. It's worth noting that when using the v3 SDK the issues didn't show up immediately, it would take a few days or more before we'd have a task get hung up and terminated due to being non-responsive. We are only creating one instance of the client. https://github.com/aws/aws-sdk-js-v3/issues/4596 seems to be related to the issues discussed here and some are saying that the config in https://github.com/aws/aws-sdk-js-v3/issues/3560#issuecomment-1484140333 fixes the issue for them.
When upgrading to v3 do we still need to apply the changes from https://github.com/aws/aws-sdk-js-v3/issues/3560#issuecomment-1484140333 or should it be fine without it? If so, any idea why this would be required in v3 and was not in v2?
We are theorizing here without more specific reproduction examples, but one thing to keep in mind is that in the v2 SDK, the S3 objects are buffered by default when you request them (reading the stream).
In v3, the S3::getObject request only opens a stream. You must consume the stream or garbage collect the client or its request handler to keep the connections open to new traffic. One example, reading the stream into a string:
// v2
const get = await s3.getObject({ ... }).promise(); // this buffers (consumes) the stream already.
// v3
const get = await s3.getObject({ ... }); // object .Body has unconsumed stream.
const str = await get.Body.transformToString(); // consumes the stream.
So I managed to fix all my issues.
- Socket hang up happens when I use the same client for all the requests. It was not enough amount of sockets to maintain so many simultaneous requests. So I am creating a new client and generating a new set of credentials for it every request
- I am not using fromInstanceMetadata() to get creds or anything like that because IMDS is too slow and it is slowing down the entire process. Instead I am getting creds from AssumeRoleCommand, saving them as env vars and consuming them through fromEnv(). I set up a cronjob or a simple setInterval to refresh creds because of AssumeRole session that is tend to expire.
Now V2 and V3 performance is similar
The solution provided in here https://github.com/aws/aws-sdk-js-v3/issues/3560#issuecomment-1484140333 has worked great for us. I'm a little hazy on the details (it's been a minute), but IIRC it effectively "reverts" the v3 http agent settings back to aws-sdk v2's settings, which solved the problems for us:
import { S3Client } from "@aws-sdk/client-s3";
import { NodeHttpHandler } from "@smithy/node-http-handler";
import { Agent as HttpAgent } from "node:http";
import { Agent as HttpsAgent } from "node:https";
const connectionTimeout = 5000;
const socketTimeout = 120000;
const maxSockets = 500;
const keepAlive = true;
const client = new S3Client({
requestHandler: new NodeHttpHandler({
connectionTimeout,
socketTimeout,
httpAgent: new HttpAgent({ maxSockets, keepAlive }),
httpsAgent: new HttpsAgent({ maxSockets, keepAlive }),
}),
});
Our problem was that bad requests/operations would never timeout, which combined with the the low default maxSockets meant at a certain point all sockets were in use for requests that were long timed out / dead, which in turn made our endpoints "hang" and be unresponsive.
👋
When downloading hundreds of files from s3 using v3 SDK we experience this issue on lambda which stops SILENTLY working after around 150 files most of the time. Sometimes it works, it depends on the gods of the network.
There are no warning or error logs, even inside the SDK when providing a logger. So we investigate for quite a long time before finding this issue and the possible workarounds.
Is it possible to have a log or an event or something to know when the SDK is stuck because of lack of available sockets?
I don't think that downloading 200 files to transform them using streams is an edge case and this issue deserves an improvement they would help troubleshooting the issue without reading hundreds of web pages on SO or GitHub.
@clakech did you try using higher values for maxSockets?
@rijkvanzanten socketTimeout is actually deprecated, you should use requestTimeout instead
Summary of AWS Lambda Challenges and Optimizations
Issue Encountered:
When using AWS Lambda, the "GetObjectCommand" is utilized to handle the same problem in AWS Lambda. When a client sends a request, an error message may occur:
WARN @smithy/node-http-handler:WARN socket usage at capacity=50 and 131 (any number over 50) additional requests are enqueued. See Node Configuring MaxSockets or increase socketAcquisitionWarningTimeout=(millis) in the NodeHttpHandler config.
Implementation Details:
I employed Lambda to automate the process of handling image uploads to S3 bucket A. The process involves listening to events in bucket A and triggering Lambda functions. The main steps in the Lambda function implementation are as follows:
- Obtain the image and metadata using the "GetObjectCommand".
- Compress the images using Sharp.
- Re-upload the compressed image to S3 bucket A. Note: This step may trigger a recursive call, necessitating the implementation of logic to prevent recursion.
Challenges Faced:
One significant challenge encountered was the need for recursive calls within the same bucket. When a user uploads an image to S3, triggering Lambda to process and store the compressed image back into the same bucket can lead to infinite recursion. To address this, I implemented a tagging mechanism to skip compressed processing. However, this approach resulted in suboptimal function call costs and performance.
Optimization Strategies Implemented:
To mitigate the challenges and enhance performance, I made the following optimizations:
- Adjusted socket settings and timeout configurations, setting
keepAliveto false to resolve certain issues:
const agentOptions = {
keepAlive: false,
maxSockets: 1000, // default 50
};
const httpAgent = new http.Agent(agentOptions);
const httpsAgent = new https.Agent(agentOptions);
const config = {
region,
credentials: {
accessKeyId,
secretAccessKey,
},
forcePathStyle: true,
requestHandler: new NodeHttpHandler({
httpAgent: httpAgent,
httpsAgent: httpsAgent,
}),
connectionTimeout: 1000,
requestTimeout: 5000, // default 0
};
- Ensured that the stream is consumed:
const response = await client.send(getObjectcommand);
const imgData = await response.Body.transformToByteArray(); // consumes the stream
- Properly destroyed the client when the operation is completed:
await client.send(PutCommand);
client.destroy();
By implementing these optimizations, I successfully resolved the recursion issue and improved the overall function duration and performance. Future considerations will include separating the triggering and compression processes after bucket separation.
The problem is still there but in a different shape, right now we receive a bunch of the
Socket timed out without establishing a connection within 1000 ms
The problem is that retry does not really do anything, and just fails the actual request. Does anyone have any ideas for workaround?
We are theorizing here without more specific reproduction examples, but one thing to keep in mind is that in the v2 SDK, the S3 objects are buffered by default when you request them (reading the stream).
In v3, the S3::getObject request only opens a stream. You must consume the stream or garbage collect the client or its request handler to keep the connections open to new traffic. One example, reading the stream into a string:
// v2 const get = await s3.getObject({ ... }).promise(); // this buffers (consumes) the stream already.// v3 const get = await s3.getObject({ ... }); // object .Body has unconsumed stream. const str = await get.Body.transformToString(); // consumes the stream.
I use "transformToByteArray" ,
is the same with "transformToString"?
const str = await get.Body.transformToByteArray(); // consumes the stream.