Jakarta Servlet 5.0 リクエスト処理時の例外

f:id:bau1537:20210925143925j:plain

  • Servlet がリクエストを処理中に例外をスローするとどうなるのか?
    • 仕様ではこちらで言及されている模様
    • 内容としては
      • Servlet はリクエスト処理中に ServletExceptionUnavailableException を投げる可能性がある
      • ServletException はリクエスト処理中に何らかのエラーが発生したことを示す例外であり、Servlet Container は適切に request かつ response をクリーンアップすること
      • UnavailableExceptionServlet が一時的、または永続的にリクエストを処理できないことを示す例外
        • 永続的にリクエストを処理できない場合は Servlet は取り除かれ、 destroy メソッドが呼ばれる
          • 以降 HTTP Status Code は 404 が返る
        • 一時的にリクエストを処理できない場合は指定された時間リクエストを受け付けなくなる
          • 一時的に HTTP Status Code 503 が返る
        • Servlet Container は一時的、永続的な意味を解釈せず、どちらも永続的とみなす可能性がある
          • Servlet Container を意識したくないのであれば UnavailableException を使わないほうがいいかも
          • というか、なんでこんな仕様になってるんだろう?
  • 試す

環境

$ java -jar $JETTY_HOME/start.jar --version

Jetty Server Classpath:
-----------------------
Version Information on 22 entries in the classpath.
Note: order presented here is how they would appear on the classpath.
      changes to the --module=name command line options will be reflected here.
 0:                    (dir) | ${jetty.base}/resources
 1:             2.0.0-alpha1 | ${jetty.home}/lib/logging/slf4j-api-2.0.0-alpha1.jar
 2:                   11.0.6 | ${jetty.home}/lib/logging/jetty-slf4j-impl-11.0.6.jar
 3:                    5.0.2 | ${jetty.home}/lib/jetty-jakarta-servlet-api-5.0.2.jar
 4:                   11.0.6 | ${jetty.home}/lib/jetty-http-11.0.6.jar
 5:                   11.0.6 | ${jetty.home}/lib/jetty-server-11.0.6.jar
 6:                   11.0.6 | ${jetty.home}/lib/jetty-xml-11.0.6.jar
 7:                   11.0.6 | ${jetty.home}/lib/jetty-util-11.0.6.jar
 8:                   11.0.6 | ${jetty.home}/lib/jetty-io-11.0.6.jar
 9:                   11.0.6 | ${jetty.home}/lib/jetty-jndi-11.0.6.jar
10:                   11.0.6 | ${jetty.home}/lib/jetty-security-11.0.6.jar
11:                   11.0.6 | ${jetty.home}/lib/jetty-servlet-11.0.6.jar
12:                   11.0.6 | ${jetty.home}/lib/jetty-webapp-11.0.6.jar
13:                   11.0.6 | ${jetty.home}/lib/jetty-plus-11.0.6.jar
14:                    2.0.0 | ${jetty.home}/lib/jakarta.transaction-api-2.0.0.jar
15:                   11.0.6 | ${jetty.home}/lib/jetty-annotations-11.0.6.jar
16:                      9.1 | ${jetty.home}/lib/annotations/asm-9.1.jar
17:                      9.1 | ${jetty.home}/lib/annotations/asm-analysis-9.1.jar
18:                      9.1 | ${jetty.home}/lib/annotations/asm-commons-9.1.jar
19:                      9.1 | ${jetty.home}/lib/annotations/asm-tree-9.1.jar
20:                    2.0.0 | ${jetty.home}/lib/annotations/jakarta.annotation-api-2.0.0.jar
21:                   11.0.6 | ${jetty.home}/lib/jetty-deploy-11.0.6.jar
  • プロジェクト
.
├── pom.xml
└── src
    └── main
        └── java
            └── org
                └── example
                    └── servlet
                        └── DemoServlet.java

6 directories, 2 files
  • pom
<?xml version="1.0" encoding="UTF-8"?>

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>org.example</groupId>
    <artifactId>servlet</artifactId>
    <version>1.0-SNAPSHOT</version>
    <packaging>war</packaging>

    <name>Servlet Maven Webapp</name>

    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <maven.compiler.source>11</maven.compiler.source>
        <maven.compiler.target>11</maven.compiler.target>
    </properties>

    <dependencies>
        <dependency>
            <groupId>jakarta.servlet</groupId>
            <artifactId>jakarta.servlet-api</artifactId>
            <version>5.0.0</version>
            <scope>provided</scope>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-war-plugin</artifactId>
                <version>3.2.2</version>
                <configuration>
                    <failOnMissingWebXml>false</failOnMissingWebXml>
                </configuration>
            </plugin>
        </plugins>
    </build>
</project>

ServletException

package org.example.servlet;

import jakarta.servlet.ServletException;
import jakarta.servlet.annotation.WebServlet;
import jakarta.servlet.http.HttpServlet;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;

import java.io.IOException;
import java.io.PrintWriter;

@WebServlet(urlPatterns = "/")
public class DemoServlet extends HttpServlet {

    @Override
    public void init() {
        log("Servlet init");
    }

    @Override
    public void destroy() {
        log("Servlet destroy");
    }

    @Override
    protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws IOException, ServletException {
        log("Servlet handle get request");
        PrintWriter writer = resp.getWriter();
        writer.write("hello from Jakarta Servlet 5");
        throw new ServletException("demo exception");
    }

}
  • デプロイし、アクセスしたときのログ
    • HTTP Status Code は 500 が返される
    • 何度もアクセスしてもリクエストをハンドリングしたログが繰り返し出力されるため、 Servlet が取り除かれているわけではない
2021-09-26 16:58:22.876:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet init
2021-09-26 16:58:22.876:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet handle get request
2021-09-26 16:58:22.877:WARN :oejs.HttpChannel:qtp293907205-25: /servlet-1.0-SNAPSHOT/
jakarta.servlet.ServletException: demo exception
    at org.example.servlet.DemoServlet.doGet(DemoServlet.java:30)
    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:500)
    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
    at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1410)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:508)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:580)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1370)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:463)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1292)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:192)
    at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:51)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
    at org.eclipse.jetty.server.Server.handle(Server.java:562)
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:406)
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:663)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:398)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:319)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
    at org.eclipse.jetty.io.SocketChannelEndPoint$1.run(SocketChannelEndPoint.java:101)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:894)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1038)
    at java.base/java.lang.Thread.run(Thread.java:831)

UnavailableException

  • UnavailableException を投げるとログはこうなる
    • HTTP Status Code は 404 が返ってきた
    • 何度アクセスしてもリクエストをハンドリングしたというログは出てこないので、Servlet が取り除かれているようだ
    • つまり、もう Servlet へリクエストを送ることができなくなっている
    • destroy が呼び出されていないようだが、コードが間違っているのか?もしかしてJettyがよろしくないのか?
      • それっぽいIssueを見つけたが2016年にCloseされている
      • https://github.com/eclipse/jetty.project/issues/97
      • 手元の環境では Jettyを終了させるときには destroy が呼ばれているが、これが正しい挙動なのかは微妙
2021-09-26 17:20:31.472:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet init
2021-09-26 17:20:31.472:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet handle get request
  • 例外クラスに5秒指定してみる
    @Override
    protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws IOException, ServletException {
        log("Servlet handle get request");
        PrintWriter writer = resp.getWriter();
        writer.write("hello from Jakarta Servlet 5");
        throw new UnavailableException("demo exception", 5);
    }
  • ログはこうなる
    • 5秒間 HTTP Status Code は 503 を返すようになった
      • その間、リクエストをハンドリングするログは出ていないので、 Servlet にリクエストが届いていない
    • 5秒立つとリクエストをハンドリングするログが出るようになる
    • つまり、指定した期間 503 を返し、その後通常処理にもどる
    • Servlet は取り除かれない
2021-09-26 17:24:20.908:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet init
2021-09-26 17:24:20.909:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet handle get request
2021-09-26 17:24:28.868:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-34: org.example.servlet.DemoServlet: Servlet handle get request
2021-09-26 17:24:33.916:INFO :oejshC.servlet_1_0_SNAPSHOT:qtp293907205-25: org.example.servlet.DemoServlet: Servlet handle get request