Provisioned Concurrencyを使ってみての一意見

はじめに

Provisioned Concurrencyを使用したDynamoDBに接続するLambdaで性能に関する問題が発覚しました。
それについて試したことや記事タイトルの通り、Provisioned Concurrencyについて考えさせられる部分があったため、記事にしました。

経緯

前述の通り、Provisioned Concurrencyを使用したDynamoDBに接続するLambdaでWebAPIを作成していました。
Provisioned Concurrencyの効果を最大限にしたいので、Provisioned Concurrencyの準備中にハンドラー外の初期化処理に加え、DynamoDBクライアントをグローバルで初期化したり、DynamoDBと接続を行いコネクションを事前に確立させておきました。
以上の施策により、後続リクエストのスループットの向上を試みました。

ぶつかった問題

上述の通り、Provisioned Concurrency準備中に諸々準備しておくことで後続リクエストのスループットが向上できる認識でした。
しかし、実際負荷試験ツールでリクエストを投げてみるとProvisioned Concurrency準備完了後の最初のリクエストのレイテンシが大きくなる傾向がありました。

やったこと

ログ確認（KeepAliveなし）

以下の記事を参考にLambda実行ログにDynamoDBとの接続で使用しているポート番号を出力するようソースを修正しました。
ポート番号はハンドラー外ないしハンドラー内で出力するようにしています。
また、DynamoDBへクエリを投げてから結果が返却されるまでの処理時間もログに出力します。

Lambdaに関する情報を下記に示します。

• メモリ：256MB
• Provisioned Concurrency：1
• ランタイム：Node.js 20.x
• アーキテクチャ：x86_64
• SDKバージョン：@aws-sdk/client-dynamodb@3.518.0

Lambda関数のソースは以下を参照ください。

なお、LambdaのKeepAlive設定はソース上、環境変数上（AWS_NODEJS_CONNECTION_REUSE_ENABLED）で明示的に無効化しています。

const agent = new Agent({
  keepAlive: false,
});

4ケースでのLambda実行ログを収集しました。

• Provisioned Concurrency準備中
• Provisioned Concurrency準備完了直後
• 前回の実行から1分以内にLambdaを実行
• 前回の実行から1分5秒後にLambdaを実行

主要な情報をまとめたのが以下です。

No.	Lambda開始時間	ケース	DynamoDBレイテンシ(ms)	Duration(ms)	ポート
1	12:24:14.613Z	①Provisioned Concurrency準備中	462.607	-	56816
2	12:25:41.671Z	②Provisioned Concurrency準備完了直後（約1分半後、ポート変更）	120.346	1220.41	38616
3	12:26:01.195Z	③約20秒後（ポート変更）	98.379	448.36	41006
4	12:27:00.728Z	④約1分後その１（ポート変更）	66.93	471.70	42324
5	12:28:06.257Z	⑤約1分5秒後その１（ポート変更）	101.498	487.16	45976
6	12:29:06.374Z	⑥約1分後その２（ポート変更）	83.073	444.54	36648
7	12:30:12.282Z	⑦約1分5秒後その２（ポート変更）	65.295	468.45	60146

結果をまとめます。

• Provisioned　Concurrencyが準備開始されてから完了するまでおおよそ1分半以上かかる
• DynamoDBのレイテンシはProvisioned Concurrency準備完了直後がもっとも大きく（120.346ms）、それ以降は80ms前後であった
• DurationもProvisioned Concurrency準備完了後がもっとも大きく（1220.41ms）、それ以降は500ms前後であった

参考として各ケースでのログ抜粋を以下に示します。

①Provisioned Concurrency準備中

2024-03-09T12:24:14.613Z  INIT_START Runtime Version: nodejs:20.v18	Runtime Version ARN: arn:aws:lambda:ap-northeast-1::runtime:b8c2913782bf648152634d2f893a4c02250aec5884edb545f64c2bd7268d214e
2024-03-09T12:24:16.451Z	undefined	INFO	AWS_LAMBDA_INITIALIZATION_TYPE1 { AWS_LAMBDA_INITIALIZATION_TYPE: 'provisioned-concurrency' }
2024-03-09T12:24:16.951Z	undefined	INFO	getTest: 462.607ms
2024-03-09T12:24:16.951Z	undefined	INFO	requestHandler NodeHttpHandler {
  socketWarningTimestamp: 0,
  metadata: { handlerProtocol: 'http/1.1' },
  configProvider: Promise {
    {
      connectionTimeout: undefined,
      requestTimeout: 50,
      httpAgent: [Agent],
      httpsAgent: [Agent]
    }
  },
  config: {
    connectionTimeout: undefined,
    requestTimeout: 50,
    httpAgent: Agent {
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      defaultPort: 80,
      protocol: 'http:',
      options: [Object: null prototype],
      requests: [Object: null prototype] {},
      sockets: [Object: null prototype] {},
      freeSockets: [Object: null prototype] {},
      keepAliveMsecs: 1000,
      keepAlive: true,
      maxSockets: 50,
      maxFreeSockets: 256,
      scheduling: 'lifo',
      maxTotalSockets: Infinity,
      totalSocketCount: 0,
      [Symbol(shapeMode)]: false,
      [Symbol(kCapture)]: false
    },
    httpsAgent: Agent {
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      defaultPort: 443,
      protocol: 'https:',
      options: [Object: null prototype],
      requests: [Object: null prototype] {},
      sockets: [Object: null prototype],
      freeSockets: [Object: null prototype] {},
      keepAliveMsecs: 1000,
      keepAlive: false,
      maxSockets: Infinity,
      maxFreeSockets: 256,
      scheduling: 'lifo',
      maxTotalSockets: Infinity,
      totalSocketCount: 1,
      maxCachedSessions: 100,
      _sessionCache: [Object],
      [Symbol(shapeMode)]: false,
      [Symbol(kCapture)]: false
    }
  }
}
2024-03-09T12:24:16.969Z	undefined	INFO	agent Agent {
  _events: [Object: null prototype] {
    free: [Function (anonymous)],
    newListener: [Function: maybeEnableKeylog]
  },
  _eventsCount: 2,
  _maxListeners: undefined,
  defaultPort: 443,
  protocol: 'https:',
  options: [Object: null prototype] {
    keepAlive: false,
    noDelay: true,
    path: null
  },
  requests: [Object: null prototype] {},
  sockets: [Object: null prototype] {
    'dynamodb.ap-northeast-1.amazonaws.com:443:::::::::::::::::::::': [ [TLSSocket] ]
  },
  freeSockets: [Object: null prototype] {},
  keepAliveMsecs: 1000,
  keepAlive: false,
  maxSockets: Infinity,
  maxFreeSockets: 256,
  scheduling: 'lifo',
  maxTotalSockets: Infinity,
  totalSocketCount: 1,
  maxCachedSessions: 100,
  _sessionCache: { map: {}, list: [] },
  [Symbol(shapeMode)]: false,
  [Symbol(kCapture)]: false
}
2024-03-09T12:24:16.970Z	undefined	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 56816

②Provisioned Concurrency準備完了直後（約1分半後、ポート変更）

2024-03-09T12:25:41.671Z  START RequestId: 4fd9781e-4d93-4a90-87b4-e637afd92e9f Version: 43
...
2024-03-09T12:25:42.192Z	4fd9781e-4d93-4a90-87b4-e637afd92e9f	INFO	getTest: 120.346ms
...
2024-03-09T12:25:42.194Z	4fd9781e-4d93-4a90-87b4-e637afd92e9f	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 38616
...
REPORT RequestId: 4fd9781e-4d93-4a90-87b4-e637afd92e9f	Duration: 1220.41 ms	Billed Duration: 1221 ms	Memory Size: 256 MB	Max Memory Used: 86 MB	Init Duration: 2395.82 ms	

③約20秒後（ポート変更）

2024-03-09T12:26:01.195Z  START RequestId: 3679af47-c1e1-44cb-a292-fc0dbc1a0b09 Version: 43
...
2024-03-09T12:26:01.452Z	3679af47-c1e1-44cb-a292-fc0dbc1a0b09	INFO	getTest: 98.379ms
...
2024-03-09T12:26:01.452Z	3679af47-c1e1-44cb-a292-fc0dbc1a0b09	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 41006
...
REPORT RequestId: 3679af47-c1e1-44cb-a292-fc0dbc1a0b09	Duration: 448.36 ms	Billed Duration: 449 ms	Memory Size: 256 MB	Max Memory Used: 87 MB	

④約1分後その１（ポート変更）

2024-03-09T12:27:00.728Z  START RequestId: 6f93b7ba-21c9-4cab-b04a-27b1540fa76e Version: 43
...
2024-03-09T12:27:00.979Z	6f93b7ba-21c9-4cab-b04a-27b1540fa76e	INFO	getTest: 66.93ms
...
2024-03-09T12:27:00.993Z	6f93b7ba-21c9-4cab-b04a-27b1540fa76e	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 42324
...
REPORT RequestId: 6f93b7ba-21c9-4cab-b04a-27b1540fa76e	Duration: 471.70 ms	Billed Duration: 472 ms	Memory Size: 256 MB	Max Memory Used: 87 MB

⑤約1分5秒後その１（ポート変更）

2024-03-09T12:28:06.257Z  START RequestId: 1d4beb4d-bdf3-4c1d-8658-f05038466778 Version: 43
...
2024-03-09T12:28:06.535Z	1d4beb4d-bdf3-4c1d-8658-f05038466778	INFO	getTest: 101.498ms
...
2024-03-09T12:28:06.554Z	1d4beb4d-bdf3-4c1d-8658-f05038466778	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 45976
...
REPORT RequestId: 1d4beb4d-bdf3-4c1d-8658-f05038466778	Duration: 487.16 ms	Billed Duration: 488 ms	Memory Size: 256 MB	Max Memory Used: 88 MB

⑥約1分後その２（ポート変更）

2024-03-09T12:29:06.374Z  START RequestId: f6122dd5-8ed0-47a2-b668-2503bcb4b26f Version: 43
...
2024-03-09T12:29:06.638Z	f6122dd5-8ed0-47a2-b668-2503bcb4b26f	INFO	getTest: 83.073ms
...
2024-03-09T12:29:06.655Z	f6122dd5-8ed0-47a2-b668-2503bcb4b26f	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 36648
...
REPORT RequestId: f6122dd5-8ed0-47a2-b668-2503bcb4b26f	Duration: 444.54 ms	Billed Duration: 445 ms	Memory Size: 256 MB	Max Memory Used: 88 MB	

⑦約1分5秒後その２（ポート変更）

2024-03-09T12:30:12.282Z  START RequestId: 1d9ef450-b4ca-479e-88bc-a0cbd1c1ddda Version: 43
...
2024-03-09T12:30:12.542Z	1d9ef450-b4ca-479e-88bc-a0cbd1c1ddda	INFO	getTest: 65.295ms
...
2024-03-09T12:30:12.542Z	1d9ef450-b4ca-479e-88bc-a0cbd1c1ddda	INFO	sockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 60146
...
REPORT RequestId: 1d9ef450-b4ca-479e-88bc-a0cbd1c1ddda	Duration: 468.45 ms	Billed Duration: 469 ms	Memory Size: 256 MB	Max Memory Used: 88 MB	

ログ確認（KeepAliveあり）

Lambda側からのTCP KeepAliveの設定は上記で回答者様からアドバイスを頂き、以下の設定となっています。

const agent = new Agent({
  keepAlive: true,
  keepAliveMsecs: 500,
  maxSockets: 10,
  maxTotalSockets: 50,
  maxFreeSockets: 10,
  keepAliveInitialDelay: 500,
  noDelay: true,
  timeout: 150000,
  scheduling: "fifo",
});

主要な情報をまとめたのが以下です。

No.	Lambda開始時間	ケース	DynamoDBレイテンシ(ms)	Duration(ms)	ポート
1	14:31:54.641Z	①Provisioned Concurrency準備中	461.182	-	42692
2	14:33:21.489Z	②Provisioned Concurrency準備完了直後（約1分半後、ポート変更）	256.56	1281.08	59236
3	14:34:02.640Z	③約30秒後（ポート維持）	21.163	420.63	59236
4	14:35:02.667Z	④約1分後その１（ポート維持）	20.232	393.81	59236
5	14:36:08.242Z	⑤約1分5秒後その１（ポート変更）	70.111	407.46	49624
6	14:37:08.344Z	⑥約1分後その２（ポート維持）	20.287	349.38	49624
7	14:38:15.001Z	⑦約1分5秒後その２（ポート変更）	74.318	406.58	53682
8	14:39:20.173Z	⑧約1分5秒後その３（ポート変更）	182.515	602.94	45810
9	14:40:19.152Z	⑨約1分後その３（ポート維持）	20.482	369.89	45810

結果をまとめます。

• Provisioned　Concurrencyが準備開始されてから完了するまでおおよそ1分半以上かかる（KeepAliveありと同様）
• DynamoDBのレイテンシはProvisioned Concurrency準備完了直後がもっとも大きかった（256.56ms）（KeepAliveありと同様）
• DynamoDBのレイテンシはポートが維持された場合、20ms前後であった
• DynamoDBのレイテンシはポートが変更された場合、70msから180ms前後であった（KeepAliveありとほぼ同様）
• DurationもProvisioned Concurrency準備完了後がもっとも大きく（1281.08ms）、それ以降は400msから500ms前後であった

参考として各ケースでのログ抜粋を以下に示します。

①Provisioned Concurrency準備中

2024-03-05T14:31:54.641Z	INIT_START Runtime Version: nodejs:20.v16	Runtime Version ARN: arn:aws:lambda:ap-northeast-1::runtime:660a9e193c3308bf378f98e9cccc1c6e75c9c39c457df58189605033509e1044
2024-03-05T14:31:56.332Z	undefined	INFO	AWS_LAMBDA_INITIALIZATION_TYPE1 { AWS_LAMBDA_INITIALIZATION_TYPE: 'provisioned-concurrency' }
2024-03-05T14:31:56.831Z	undefined	INFO	getTest: 461.182ms
2024-03-05T14:31:56.831Z	undefined	INFO	requestHandler NodeHttpHandler {
  socketWarningTimestamp: 0,
  metadata: { handlerProtocol: 'http/1.1' },
  configProvider: Promise {
    {
      connectionTimeout: undefined,
      requestTimeout: 50,
      httpAgent: [Agent],
      httpsAgent: [Agent]
    }
  },
  config: {
    connectionTimeout: undefined,
    requestTimeout: 50,
    httpAgent: Agent {
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      defaultPort: 80,
      protocol: 'http:',
      options: [Object: null prototype],
      requests: [Object: null prototype] {},
      sockets: [Object: null prototype] {},
      freeSockets: [Object: null prototype] {},
      keepAliveMsecs: 1000,
      keepAlive: true,
      maxSockets: 50,
      maxFreeSockets: 256,
      scheduling: 'lifo',
      maxTotalSockets: Infinity,
      totalSocketCount: 0,
      [Symbol(shapeMode)]: false,
      [Symbol(kCapture)]: false
    },
    httpsAgent: Agent {
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      defaultPort: 443,
      protocol: 'https:',
      options: [Object: null prototype],
      requests: [Object: null prototype] {},
      sockets: [Object: null prototype] {},
      freeSockets: [Object: null prototype],
      keepAliveMsecs: 500,
      keepAlive: true,
      maxSockets: 10,
      maxFreeSockets: 10,
      scheduling: 'fifo',
      maxTotalSockets: 50,
      totalSocketCount: 1,
      maxCachedSessions: 100,
      _sessionCache: [Object],
      [Symbol(shapeMode)]: false,
      [Symbol(kCapture)]: false
    }
  }
}
2024-03-05T14:31:56.832Z	undefined	INFO	agent Agent {
  _events: [Object: null prototype] {
    free: [Function (anonymous)],
    newListener: [Function: maybeEnableKeylog]
  },
  _eventsCount: 2,
  _maxListeners: undefined,
  defaultPort: 443,
  protocol: 'https:',
  options: [Object: null prototype] {
    keepAlive: true,
    keepAliveMsecs: 500,
    maxSockets: 10,
    maxTotalSockets: 50,
    maxFreeSockets: 10,
    keepAliveInitialDelay: 500,
    noDelay: true,
    timeout: 120000,
    scheduling: 'fifo',
    path: null
  },
  requests: [Object: null prototype] {},
  sockets: [Object: null prototype] {},
  freeSockets: [Object: null prototype] {
    'dynamodb.ap-northeast-1.amazonaws.com:443:::::::::::::::::::::': [ [TLSSocket] ]
  },
  keepAliveMsecs: 500,
  keepAlive: true,
  maxSockets: 10,
  maxFreeSockets: 10,
  scheduling: 'fifo',
  maxTotalSockets: 50,
  totalSocketCount: 1,
  maxCachedSessions: 100,
  _sessionCache: { map: {}, list: [] },
  [Symbol(shapeMode)]: false,
  [Symbol(kCapture)]: false
}
2024-03-05T14:31:56.833Z	undefined	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 42692

②Provisioned Concurrency準備完了直後（約1分半後、ポート変更）

2024-03-05T14:33:21.489Z	START RequestId: 348d857d-01ae-489c-ab84-64c389fe5070 Version: 42
2024-03-05T14:33:21.813Z	348d857d-01ae-489c-ab84-64c389fe5070	INFO	AWS_LAMBDA_INITIALIZATION_TYPE2 { AWS_LAMBDA_INITIALIZATION_TYPE: 'provisioned-concurrency' }
2024-03-05T14:33:22.070Z	348d857d-01ae-489c-ab84-64c389fe5070	INFO	getTest: 256.56ms
...
2024-03-05T14:33:22.072Z	348d857d-01ae-489c-ab84-64c389fe5070	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 59236
...
REPORT RequestId: 348d857d-01ae-489c-ab84-64c389fe5070	Duration: 1281.08 ms	Billed Duration: 1282 ms	Memory Size: 256 MB	Max Memory Used: 85 MB	Init Duration: 2229.18 ms

③約30秒後（ポート維持）

2024-03-05T14:34:02.640Z	START RequestId: 95f74367-164c-4037-ba2e-18ec0f33e3f2 Version: 42
...
2024-03-05T14:34:02.832Z	95f74367-164c-4037-ba2e-18ec0f33e3f2	INFO	getTest: 21.163ms
...
2024-03-05T14:34:02.851Z	95f74367-164c-4037-ba2e-18ec0f33e3f2	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 59236
...
REPORT RequestId: 95f74367-164c-4037-ba2e-18ec0f33e3f2	Duration: 420.63 ms	Billed Duration: 421 ms	Memory Size: 256 MB	Max Memory Used: 86 MB	

④約1分後その１（ポート維持）

2024-03-05T14:35:02.667Z	START RequestId: 196d01e7-b713-4f92-a1c6-cf0d20035e65 Version: 42
...
2024-03-05T14:35:02.851Z	196d01e7-b713-4f92-a1c6-cf0d20035e65	INFO	getTest: 20.232ms
...
2024-03-05T14:35:02.871Z	196d01e7-b713-4f92-a1c6-cf0d20035e65	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 59236
...
REPORT RequestId: 196d01e7-b713-4f92-a1c6-cf0d20035e65	Duration: 393.81 ms	Billed Duration: 394 ms	Memory Size: 256 MB	Max Memory Used: 86 MB	

⑤約1分5秒後その１（ポート変更）

2024-03-05T14:36:08.242Z	START RequestId: 2a1036c3-5ce3-45d5-82d7-131ba8be5aa6 Version: 42
...
2024-03-05T14:36:08.481Z	2a1036c3-5ce3-45d5-82d7-131ba8be5aa6	INFO	getTest: 70.111ms
...
2024-03-05T14:36:08.482Z	2a1036c3-5ce3-45d5-82d7-131ba8be5aa6	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 49624
...
REPORT RequestId: 2a1036c3-5ce3-45d5-82d7-131ba8be5aa6	Duration: 407.46 ms	Billed Duration: 408 ms	Memory Size: 256 MB	Max Memory Used: 87 MB	

⑥約1分後その２（ポート維持）

2024-03-05T14:37:08.344Z	START RequestId: 20200d4f-f254-40c1-9d4d-a67e2a8388b0 Version: 42
...
2024-03-05T14:37:08.532Z	20200d4f-f254-40c1-9d4d-a67e2a8388b0	INFO	getTest: 20.287ms
...
2024-03-05T14:37:08.533Z	20200d4f-f254-40c1-9d4d-a67e2a8388b0	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 49624
...
REPORT RequestId: 20200d4f-f254-40c1-9d4d-a67e2a8388b0	Duration: 349.38 ms	Billed Duration: 350 ms	Memory Size: 256 MB	Max Memory Used: 87 MB	

⑦約1分5秒後その２（ポート変更）

2024-03-05T14:38:15.001Z	START RequestId: 21a653ed-47e4-4803-bb6c-a9d643d62368 Version: 42
...
2024-03-05T14:38:15.246Z	21a653ed-47e4-4803-bb6c-a9d643d62368	INFO	getTest: 74.318ms
...
2024-03-05T14:38:15.247Z	21a653ed-47e4-4803-bb6c-a9d643d62368	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 53682
...
REPORT RequestId: 21a653ed-47e4-4803-bb6c-a9d643d62368	Duration: 406.58 ms	Billed Duration: 407 ms	Memory Size: 256 MB	Max Memory Used: 87 MB	

⑧約1分5秒後その３（ポート変更）

2024-03-05T14:39:20.173Z	START RequestId: d57ad84a-5df8-4d00-8999-d238e3a1161d Version: 42
...
2024-03-05T14:39:20.555Z	d57ad84a-5df8-4d00-8999-d238e3a1161d	INFO	getTest: 182.515ms
...
2024-03-05T14:39:20.573Z	d57ad84a-5df8-4d00-8999-d238e3a1161d	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 45810
...
REPORT RequestId: d57ad84a-5df8-4d00-8999-d238e3a1161d	Duration: 602.94 ms	Billed Duration: 603 ms	Memory Size: 256 MB	Max Memory Used: 93 MB	

⑨約1分後その３（ポート維持）

2024-03-05T14:40:19.152Z	START RequestId: 5c997299-fada-4ba4-900b-ea199f77fde5 Version: 42
...
2024-03-05T14:40:19.353Z	5c997299-fada-4ba4-900b-ea199f77fde5	INFO	getTest: 20.482ms
...
2024-03-05T14:40:19.373Z	5c997299-fada-4ba4-900b-ea199f77fde5	INFO	freeSockets:dynamodb.ap-northeast-1.amazonaws.com:443::::::::::::::::::::: Local port: 45810
...
REPORT RequestId: 5c997299-fada-4ba4-900b-ea199f77fde5	Duration: 369.89 ms	Billed Duration: 370 ms	Memory Size: 256 MB	Max Memory Used: 93 MB	

プロファイル確認（KeepAliveあり）

Node.jsのコードプロファイラーmiddy-profilerを使用して、内部処理がどのようになっているか調査しました。
使い方は下記を参考にしました。

①Provisioned Concurrency準備中

取得できず。

②Provisioned Concurrency準備完了直後（約1分半後、ポート変更）

createSocketなど接続を生成するような処理が実行されていた。

③約30秒後（ポート維持）

createSocketなど接続を生成するような処理を見つけることができなかった。

④約1分後その１（ポート維持）

createSocketなど接続を生成するような処理を見つけることができなかった。

⑤約1分5秒後その１（ポート変更）

createSocketなど接続を生成するような処理が実行されていた。

⑥約1分後その２（ポート維持）

createSocketなど接続を生成するような処理を見つけることができなかった。

⑦約1分5秒後その２（ポート変更）

⑧約1分5秒後その３（ポート変更）

※ここが他と傾向が異なる。
createSocketなど接続を生成するような処理を見つけることができなかった。

⑨約1分後その３（ポート維持）

createSocketなど接続を生成するような処理を見つけることができなかった。

わかったこと

ログから確認できたこと

• DynamoDBのレイテンシおよびDurationは、KeepAliveの有無にかかわらずProvisioned Concurrency準備完了直後のリクエストの時がもっとも大きかった
• KeepAliveが有効になっている場合、Lambdaの前回実行から1分以内にリクエストするとポートが維持され、かつ、レイテンシが20ms前後に収まる
  • コネクションが再利用されていると判断できる
• KeepAliveが有効になっていたとしても、Lambdaの前回実行から1分5秒以上経過するとポートが変更され、かつ、レイテンシが70msから180ms前後に悪化する
  • コネクションが破棄され、再生成されていると判断できる
  • コネクションは接続先であるDynamoDBサービスから切断されていると考えられる
• Provisioned　Concurrencyが準備開始されてから完了するまでおおよそ1分半以上かかる
  • Provisioned　Concurrency完了後のリクエストはDynamoDBとのコネクションを再利用することが出来ず新規生成せざるを得ない
• Provisioned Concurrency準備完了後以外のDurationがポートの変更にかかわらず悪化していない
  • レイテンシが大きくなることの原因がコネクション以外にもある可能性は高い

プロファイルから確認できたこと

• ポート維持時はcreateSocketなど接続を生成するような処理を見つけることができなかった
• ポート変更時はcreateSocketなど接続を生成するような処理が実行されていた

その他

• Provisioned　Concurrency準備中はそのインスタンスに対してリクエストすることは出来ない
  • 準備中にリクエストしたところ、コールドスタートが発生した
  • 準備中にLambdaを実行してDynamoDBとのコネクションを維持するという方法が取れない
• Provisioned　Concurrency準備中に実行されるハンドラー外の処理が終了してから、Provisioned Concurrency準備完了までおおよそ1分半かかる
  • 準備中にLambdaからDynamoDBにクエリを投げてコネクションを維持するという方法が取れない
• なお、DynamoDBサービス内部のレイテンシを表すSuccessfulRequestLatencyはいずれも極小（10ms未満）

最後に

Provisioned Concurrencyによってインスタンスを暖気することができ、コールドスタートが実行されたときにかかる時間を大幅に短縮できるメリットは変わらないと思います。
しかし、今回のように低レイテンシを常に求めるとすれば、Provisioned Concurrencyにすべてを期待することは出来ないように感じます。

結局、Provisioned Concurrency準備完了直後のリクエストのレイテンシ、Durationが悪化する原因ははっきりしないままでしたが、コネクション関連が要因である可能性は高いと考えます。
DynamoDBのコネクションタイムアウトの仕様を考えると、Provisioned Concurrencyと多少相性が悪いように感じました。
せっかくLambda側でコネクションを再利用する処理を実装してもそれがDynamoDB側の制約でムダになってしまうということがわかったからです。
Provisioned Concurrencyの準備時間が短縮されれば解決する問題なので、今後のアップデートに期待します。

また、Provisioned Concurrencyの効果の1つとしてバースト耐性があります。
制限された同時実行数の壁を超えてLambdaと実行できる素晴らしい機能だと思います。

ただ、今回の検証でProvisioned Concurrency準備完了直後のリクエストのレイテンシ、Durationが思いのほか悪いことを知ると、バースト耐性として使用するには片手落ち感を覚えました。
（コールドスタートより十分に速いことは理解しているのですが。。）
こちらも今後のアップデートで改善されることを期待します。