AWS Lambda冷启动后首次热调用远慢于后续调用原因及优化

问题背景 #

• 部署架构：通过Serverless Framework将Kotlin开发的函数部署至AWS Lambda，采用Java运行时，单Handler作为多API端点统一入口，通过静态工厂类StrategyFactory根据路由键匹配对应处理逻辑
• 冷启动优化配置：使用Serverless Warmup插件做函数定期预热
• 核心Handler代码如下：

class MyHandler : RequestHandler<Map<String, Any>, ApiGatewayResponse> {

    private val myService = MyService()

    private val printStatement = LOG.debug("ColdStart") /* 仅冷启动阶段会打印该日志 */

    override fun handleRequest(input: Map<String, Any>, context: Context): ApiGatewayResponse {

        val startTime = System.currentTimeMillis()

        input.handleWarmup(LOG)?.let{ return it }

        val customInput : Input = Input.fromMap(input) ?: return ApiResponseHelper.generateStandardErrorResponse(Messages.MALFORMED_REQUEST, 400)

        LOG.info(customInput.routeKey)
        val strategy = StrategyFactory.getStrategy(customInput.routeKey)
                ?: return ApiResponseHelper.generateStandardErrorResponse(Messages.REQUEST_NOT_RECOGNIZED, 404)

        return try {
            LOG.debug("Before Strategy : ${System.currentTimeMillis() - startTime}")
            strategy.apply(customInput, myService)
        }
        catch(e : Exception){
            ExceptionParser.exceptionHandler(e)
        }
    }

    companion object {
        private val LOG = LogManager.getLogger(MyHandler::class.java)
    }
}

观测到的异常现象 #

1. 预热请求触发冷启动时，Init Duration为2406ms，预热请求本身耗时110ms，表现符合预期，预热日志如下：

START RequestId: 6e32e62b-2a04-4001-85ab-c0e61d48584d Version: $LATEST

2022-06-08T15:00:37.657+05:30   Picked up JAVA_TOOL_OPTIONS: -XX:+TieredCompilation -XX:TieredStopAtLevel=1

2022-06-08T15:00:39.586+05:30   Transforming org/apache/logging/log4j/core/lookup/JndiLookup (lambdainternal.CustomerClassLoader@433c675d)

2022-06-08T15:00:39.602+05:30   WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.

2022-06-08T15:00:39.602+05:30   2022-06-08 09:30:39 DEBUG MyHandler:20 - ColdStart

2022-06-08T15:00:39.680+05:30   2022-06-08 09:30:39 6e32e62b-2a04-4001-85ab-c0e61d48584d INFO MyHandler:140 - WarmUp - Lambda is warm!

2022-06-08T15:00:39.763+05:30   END RequestId: 6e32e62b-2a04-4001-85ab-c0e61d48584d

2022-06-08T15:00:39.763+05:30   REPORT RequestId: 6e32e62b-2a04-4001-85ab-c0e61d48584d Duration: 110.59 ms Billed Duration: 111 ms Memory Size: 512 MB Max Memory Used: 145 MB Init Duration: 2406.90 ms

2. 预热完成间隔8分钟后发起首次业务请求，日志无Init Duration字段、冷启动标记日志未打印，可确认非冷启动，但执行到strategy.apply方法前已耗时2944ms，总耗时达5112.63ms，性能异常，日志如下：

2022-06-08T15:08:29.071+05:30   START RequestId: ad24cf5e-17ea-4347-9931-be4eb8cbc47b Version: $LATEST

2022-06-08T15:08:31.981+05:30   2022-06-08 09:38:31 ad24cf5e-17ea-4347-9931-be4eb8cbc47b INFO MyHandler:30 - GET /posts/{id}

2022-06-08T15:08:32.019+05:30   2022-06-08 09:38:32 ad24cf5e-17ea-4347-9931-be4eb8cbc47b DEBUG MyHandler:36 - Before Strategy : 2944

2022-06-08T15:08:34.186+05:30   END RequestId: ad24cf5e-17ea-4347-9931-be4eb8cbc47b

2022-06-08T15:08:34.186+05:30   REPORT RequestId: ad24cf5e-17ea-4347-9931-be4eb8cbc47b Duration: 5112.63 ms Billed Duration: 5113 ms Memory Size: 512 MB Max Memory Used: 188 MB

3. 异常请求后立即发起第二次相同调用，执行到strategy.apply前仅耗时2ms，总耗时50.51ms，性能较首次请求提升100倍，日志如下：

2022-06-08T15:08:46.709+05:30   START RequestId: 7228e62b-e9cd-40f8-b27b-a609b9abca0e Version: $LATEST

2022-06-08T15:08:46.714+05:30   2022-06-08 09:38:46 7228e62b-e9cd-40f8-b27b-a609b9abca0e INFO MyHandler:30 - GET /shared/node/{id}/users

2022-06-08T15:08:46.714+05:30   2022-06-08 09:38:46 7228e62b-e9cd-40f8-b27b-a609b9abca0e DEBUG MyHandler:36 - Before Strategy : 2

2022-06-08T15:08:46.762+05:30   END RequestId: 7228e62b-e9cd-40f8-b27b-a609b9abca0e

2022-06-08T15:08:46.762+05:30   REPORT RequestId: 7228e62b-e9cd-40f8-b27b-a609b9abca0e Duration: 50.51 ms Billed Duration: 51 ms Memory Size: 512 MB Max Memory Used: 189 MB

根因分析 #

• 预热逻辑未覆盖核心业务路径：当前代码命中预热标记后直接返回，仅完成了Handler类构造、基础日志类加载，完全没有触发Input解析、StrategyFactory初始化、路由对应Strategy实现类加载、MyService依赖类加载的流程。JVM类加载为懒加载机制，未被执行到的类不会被提前加载、校验、链接，这部分开销全部转移到了第一次业务请求上，是前置耗时的主要来源。
• JIT分层编译的首次执行开销：当前配置的JVM参数开启了分层编译，设置为仅执行C1层级基础编译。代码第一次执行时，JVM需要先做字节码解释执行、收集运行时profile、完成基础JIT编译，这部分解释执行和编译的开销非常高；待代码执行过一次后，热点路径被编译为本地机器码缓存，后续调用直接执行本地码，性能会提升1-2个数量级，和日志中第二次调用的性能表现完全吻合。
• 静态工厂懒初始化开销：StrategyFactory作为静态类，其内部的路由映射表构建、Strategy实例预创建等逻辑，仅在第一次调用getStrategy方法时才会触发静态块初始化，这部分逻辑在预热阶段完全没有被执行，也是首次业务请求前置耗时的组成部分。

优化方案 #

• 改造预热逻辑，覆盖全核心路径：不要在命中预热标记后直接返回，在预热分支中主动执行核心初始化逻辑：提前触发所有路由对应Strategy类的加载、传入模拟payload调用Input.fromMap方法、执行MyService无副作用的初始化方法，把类加载、静态初始化的开销提前到预热阶段完成。如果需要覆盖多路由场景，可以配置预热插件发送携带不同路由标识的模拟请求，确保所有路由路径都被提前执行到。
• 提前完成核心依赖初始化：将StrategyFactory的路由映射构建、核心Strategy实例创建逻辑，从首次调用时懒加载调整为Handler类初始化阶段（构造函数/伴生对象块）执行，避免业务请求触发这部分开销。
• 调整JVM配置优化编译效率：在函数初始化阶段主动空跑一次核心业务逻辑，触发JIT对热点代码的基础编译；如果使用Java 11及以上运行时，可以适当调整分层编译阈值，降低热点代码的编译触发条件，减少首次执行的解释执行开销。
• 按路由拆分独立Lambda函数：单Handler承载过多路由会导致类加载总量过高，且新路由首次被调用时都会触发对应分支的类加载开销。按路由拆分独立函数后，每个函数仅需加载自身依赖的类，可大幅降低首次调用的类加载开销。

内容的提问来源于stack exchange，提问作者Kancha