在AWS Lambda上运行GraalVM原生镜像的问题排查

我有一个简单的RESTful Spring Boot应用，已将其转换为GraalVM Docker镜像。按照GraalVM和AWS文档编写Dockerfile构建镜像，并通过Elastic Container Registry（ECR）将该Docker镜像部署到AWS Lambda。

当前遇到的问题：使用apiproxy-aws-gateway测试函数时，日志显示应用仅需数毫秒即可启动，但15秒后会超时，Lambda与我的应用之间没有通信——尽管我已按照文档实现了RequestStreamHandler。

另外需要注意POM文件的配置：当前我将mainClass设置为应用入口类com.sse.Application；若注释该行并改用<mainClass>com.amazonaws.services.lambda.runtime.api.client.AWSLambda</mainClass>，则会触发数组越界的运行时异常。

Dockerfile #

# graalvm image as per docs
# using GraalVM-ce for JDK 17
# FROM container-registry.oracle.com/graalvm/native-image:21-ol8 AS builder
FROM ghcr.io/graalvm/graalvm-ce:ol9-java17-22 AS builder

# set the working directory to /home/app
WORKDIR /build

# copy the source code into the image for building
COPY . /build

# build
RUN ./mvnw --no-transfer-progress native:compile -Pnative -DskipTests

# as per aws example
FROM public.ecr.aws/lambda/provided:al2023

# copy byte code into server directory
COPY --from=builder /build/target/server ./server

# lambda runs byte code by just running directory
ENTRYPOINT ["./server"]

POM文件相关配置 #

<plugin>
 <groupId>org.graalvm.buildtools</groupId>
 <artifactId>native-maven-plugin</artifactId>
 <configuration>
  <!-- <mainClass>com.amazonaws.services.lambda.runtime.api.client.AWSLambda</mainClass> -->
  <mainClass>com.sse.Application</mainClass>
  <buildArgs>
   <arg>--enable-url-protocols=http</arg>
   <arg>-H:+AddAllCharsets</arg>
  </buildArgs>
 </configuration>
 <executions>
  <execution>
   <id>build-native</id>
   <goals>
    <goal>compile-no-fork</goal>
   </goals>
   <phase>package</phase>
  </execution>
 </executions>
</plugin>

RequestStreamHandler实现代码 #

/**
 * As per docs
 * */
public class ReqHandler implements RequestStreamHandler  {

    private static final Logger log = LoggerFactory.getLogger(ReqHandler.class);
    private final static SpringBootLambdaContainerHandler<AwsProxyRequest, AwsProxyResponse> handler;

    static {
        try {
            log.info("before handler");
            handler = SpringBootLambdaContainerHandler
                    .getAwsProxyHandler(Application.class);
            log.info("after handler");
        } catch (ContainerInitializationException e) {
            // if we fail here. We re-throw the exception to force another cold start
            log.error("lambda couldn't start spring application {}", e.getMessage());
            throw new RuntimeException("Could not initialize Spring Boot application", e);
        }
    }

    @Override
    public void handleRequest(InputStream input, OutputStream output, Context context) throws IOException {
        LambdaLogger logger = context.getLogger();
        logger.log("Handle request method before");
        handler.proxyStream(input, output, context);
        logger.log("Handle request method after");
    }

}

设置mainClass为com.sse.Application时的控制台错误日志 #

.   ____          _            __ _ _
/\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/  ___)| |_)| | | | | || (_| |  ) ) ) )
'  |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot ::                (v3.1.4)
2024-01-02T21:06:13.859Z  INFO 8 --- [           main] com.sse.Application                      : Starting AOT-processed Application using Java 17.0.8 with PID 8 (/var/task/server started by sbx_user1051 in /var/task)
2024-01-02T21:06:13.859Z  INFO 8 --- [           main] com.sse.Application                      : No active profile set, falling back to 1 default profile: "default"
2024-01-02T21:06:13.898Z  INFO 8 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 1997 (http)
2024-01-02T21:06:13.902Z  INFO 8 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2024-01-02T21:06:13.902Z  INFO 8 --- [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/10.1.13]
2024-01-02T21:06:13.919Z  INFO 8 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2024-01-02T21:06:13.919Z  INFO 8 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 59 ms
2024-01-02T21:06:13.964Z  INFO 8 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 1997 (http) with context path ''
2024-01-02T21:06:13.965Z  INFO 8 --- [           main] com.sse.Application                      : Started Application in 0.169 seconds (process running for 0.486)
INIT_REPORT Init Duration: 10009.81 ms  Phase: init Status: timeout
.   ____          _            __ _ _
/\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/  ___)| |_)| | | | | || (_| |  ) ) ) )
'  |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot ::                (v3.1.4)
2024-01-02T21:06:23.426Z  INFO 9 --- [           main] com.sse.Application                      : Starting AOT-processed Application using Java 17.0.8 with PID 9 (/var/task/server started by sbx_user1051 in /var/task)
2024-01-02T21:06:23.426Z  INFO 9 --- [           main] com.sse.Application                      : No active profile set, falling back to 1 default profile: "default"
2024-01-02T21:06:23.703Z  INFO 9 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 1997 (http)
2024-01-02T21:06:23.704Z  INFO 9 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2024-01-02T21:06:23.704Z  INFO 9 --- [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/10.1.13]
2024-01-02T21:06:23.804Z  INFO 9 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2024-01-02T21:06:23.804Z  INFO 9 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 322 ms
2024-01-02T21:06:24.243Z  INFO 9 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 1997 (http) with context path ''
2024-01-02T21:06:24.243Z  INFO 9 --- [           main] com.sse.Application                      : Started Application in 0.958 seconds (process running for 0.981)
INIT_REPORT Init Duration: 3003.50 ms   Phase: invoke   Status: error   Error Type: Runtime.Unknown
START RequestId: *************** Version: $LATEST

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