afnf.net

8時間ぐらいハマったのでメモ。

結論から言えば、jetty-maven-pluginの不具合です。

経緯

jetty-maven-pluginを9.2.5.v20141112に上げたら、Mavenで動かしていたSeleniumのintegration-testが動作しなくなってしまいました。

[INFO] web.xml file = file:/D:/Java/git/blog-java1/src/main/webapp/WEB-INF/web.xml
[INFO] Webapp directory = D:\Java\git\blog-java1\src\main\webapp
2014-11-23 14:41:28.958:INFO:oejq.QuickStartDescriptorGenerator:main: Quickstart generating
2014-11-23 14:41:28.964:INFO:oejsh.ContextHandler:main: Started o.e.j.m.p.JettyWebAppContext@116ef6{/blogtest,file:/D:/Java/git/blog-java1/src/main/webapp/,AVAILABLE}{file:/D:/Java/git/blog-java1/src/main/webapp/}
2014-11-23 14:41:29.620:INFO:oejsh.ContextHandler:main: Stopped o.e.j.m.p.JettyWebAppContext@116ef6{/blogtest,file:/D:/Java/git/blog-java1/src/main/webapp/,UNAVAILABLE}{file:/D:/Java/git/blog-java1/src/main/webapp/}
[INFO] Forked process starting
[INFO] Forked process startup errors, received:     at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)

UNAVAILABLEになってるのは普通？startup errorsって何？という状態。

この状態でSeleniumまで進んでも、全て503エラーになります。

pom.xmlはこんな感じ。詳細はこのエントリで。

<plugin>
  <groupId>org.eclipse.jetty</groupId>
  <artifactId>jetty-maven-plugin</artifactId>
  <version>9.2.5.v20141112</version>
  <executions>
    <execution>
      <id>run-forked-jetty</id>
      <phase>pre-integration-test</phase>
      <goals>
        <goal>stop</goal>
        <goal>run-forked</goal>
      </goals>
      <configuration>
        <contextPath>/${pom.contextPath}</contextPath>
        <jvmArgs>-Djetty.port=${selenium.jettyport} ${jacocoArgs}</jvmArgs>
        <waitForChild>true</waitForChild>
        <daemon>true</daemon>
      </configuration>
    </execution>
    <execution>
      <id>stop-jetty</id>
      <phase>post-integration-test</phase>
      <goals>
        <goal>stop</goal>
      </goals>
    </execution>
  </executions>
  <configuration>
    <systemPropertiesFile>src/filters/${pom.confdir}/config.properties</systemPropertiesFile>
    <reload>automatic</reload>
    <scanIntervalSeconds>1</scanIntervalSeconds>
    <webApp>
      <contextPath>/${pom.contextPath}</contextPath>
    </webApp>
    <stopKey>key1</stopKey>
    <stopPort>9999</stopPort>
    <stopWait>10</stopWait>
  </configuration>
</plugin>

切り分け

9.2.2.v20140723もNG、9.1.5.v20140505はOK。

run-forkedはダメだけど、runならJettyが起動する。

とりあえずJettyのログを出すために、waitForChildをfalseに変更。

[STDERR] 2014-11-23 14:59:04.409:INFO::main: Logging initialized @309ms
[STDERR] 2014-11-23 14:59:04.476:INFO:oejmp.Starter:main: Started Jetty Server
[STDERR] 2014-11-23 14:59:04.479:INFO:oejs.Server:main: jetty-9.2.5.v20141112
[STDERR] 2014-11-23 14:59:04.711:INFO:/blogtest:main: No Spring WebApplicationInitializer types detected on classpath
[STDERR] 2014-11-23 14:59:04.838:WARN:oejuc.AbstractLifeCycle:main: FAILED org.eclipse.jetty.servlet.ServletHandler@1654dfb: java.lang.IllegalStateException: Multiple servlets map to path: *.jsp: __org.eclipse.jetty.servlet.JspPropertyGroupServlet__,jsp
[STDERR] java.lang.IllegalStateException: Multiple servlets map to path: *.jsp: __org.eclipse.jetty.servlet.JspPropertyGroupServlet__,jsp
[STDERR]     at org.eclipse.jetty.servlet.ServletHandler.updateMappings(ServletHandler.java:1488)
[STDERR]     at org.eclipse.jetty.servlet.ServletHandler.doStart(ServletHandler.java:160)
[STDERR]     at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
[STDERR]     at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132)
[STDERR]     at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114)
[STDERR]     at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61)
[STDERR]     at org.eclipse.jetty.security.SecurityHandler.doStart(SecurityHandler.java:391)
[STDERR]     at org.eclipse.jetty.security.ConstraintSecurityHandler.doStart(ConstraintSecurityHandler.java:449)
[STDERR]     at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)

*.jspのサーブレットマッピングが重複？JspPropertyGroupServletってweb.xmlの<jsp-property-group>か？

で、案の定、web.xmlの<jsp-property-group>を消すと普通に起動します。切り分けできました。

原因

2014-11-23 14:41:28.958:INFO:oejq.QuickStartDescriptorGenerator:main: Quickstart generating

というログが出ていましたが、これがヒントです。

Jetty9.2.xからQuickStartという仕組みが入っています。jar等のスキャンを減らして、起動を高速化しようという試みです。それ自体は問題ない。

ただなぜかjetty-maven-pluginの9.2.xでは、run-forkedの場合にだけ、QuickStartが勝手に適用されてしまいます。頼んでないのにｗ

target/fork-web.xmlが自動生成されていました。そして・・・

<servlet-mapping>
  <servlet-name>jsp</servlet-name>
  <url-pattern>*.jsp</url-pattern>
  <url-pattern>*.jspf</url-pattern>
  <url-pattern>*.jspx</url-pattern>
  <url-pattern>*.xsp</url-pattern>
  <url-pattern>*.JSP</url-pattern>
  <url-pattern>*.JSPF</url-pattern>
  <url-pattern>*.JSPX</url-pattern>
  <url-pattern>*.XSP</url-pattern>
</servlet-mapping>
<servlet-mapping>
  <servlet-name>__org.eclipse.jetty.servlet.JspPropertyGroupServlet__</servlet-name>
  <url-pattern>*.jsp</url-pattern>
</servlet-mapping>

うん、ぶつかってる。そりゃあ起動しませんよね。

で、どうするの？

Jetty9.2.6で直るらしいです。

Bug 452261 - Multiple servlets map to path: *.jsp

org.eclipse.jetty.jsp.JettyJspServletという、JspServletのサブクラスを導入するそうです。大丈夫かなｗ