GlassFish4.1をなおしてみた

この記事は GlassFish Advent Calendar 2014の12/25分の記事です。昨日は
@backpaper0さんのGlassFishでセッションIDを生成してるところでした。


2013/11にGlassFishの商用サポートの終了がアナウンスされて私も不安に思っていましたが、冷静に考えるとGlassFishはそもそもオープンソース(CDDL/GPLv2)です。ソースが公開されているので、もし不具合や納得いかない動作があれば自分で修正することができます。

先日、Java EE Advant Calanderの12/17分の記事を書いていたときに既知の不具合を踏んだので試しになおしてみました。以下の修正案は、私がGlassFishのソースに適当に試行錯誤して修正したとても怪しいものなので、間違ってたらすいません。

@Transactionalの例外時に原因がセットされていない

私が踏んだ不具合はGLASSFISH-21172として既にJIRAに登録されている、Java EE7から導入された@Transactionalでトランザクション境界を設定した場合、トランザクション境界内からランタイム例外が投げられても原因がよくわからないものです。

2014/12/25現在においても、今のところ修正はされていません。

具体的には以下のようなコードを実行すると問題に当たります。

@Dependent
public class OrderService {
  @Inject OrderRepository repository;

  @Transactional
  public Order takeOrder(Order order) {
    return repository.persist(order);
  }
}

@Dependent
public class OrderRepository {
  @PersistenceContext private EntityManager em;

  public Order persist(Order order) {
      Order o = em.merge(order);
      throw new NullPointerException("ぬるぽ");
  }
}

RepositoryからNPEを投げてます。上記のコードを動かし、catchせずに無視すると、GlassFish4.1では以下のようにログ出力されます。

[2014-12-16T22:04:57.576+0900] [glassfish 4.1] [SEVERE] [] [org.glassfish.jersey.server.ServerRuntime$Responder] [tid: _ThreadID=30 _ThreadName=http-listener-1(5)] [timeMillis: 1418735097576] [levelValue
: 1000] [[
  An exception has been thrown from an exception mapper class org.glassfish.jersey.gf.cdi.internal.TransactionalExceptionMapper$Proxy$_$$_WeldClientProxy.
javax.transaction.TransactionalException: Managed bean with Transactional annotation and TxType of REQUIRED encountered exception during commit javax.transaction.RollbackException: Transaction marked for
 rollback.
        at org.glassfish.cdi.transaction.TransactionalInterceptorRequired.transactional(TransactionalInterceptorRequired.java:105)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:483)
        at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
        at org.jboss.weld.interceptor.chain.AbstractInterceptionChain.invokeNext(AbstractInterceptionChain.java:116)
        at org.jboss.weld.interceptor.chain.AbstractInterceptionChain.invokeNextInterceptor(AbstractInterceptionChain.java:94)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:43)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:36)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:51)
        at net.agetsuma.transactional.OrderService$Proxy$_$$_WeldSubclass.takeOrder(Unknown Source)
        .. 途中省略
Caused by: javax.transaction.RollbackException: Transaction marked for rollback.
        at com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:445)
        at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:854)
        at com.sun.enterprise.transaction.TransactionManagerHelper.commit(TransactionManagerHelper.java:81)
        at org.glassfish.cdi.transaction.TransactionalInterceptorRequired.transactional(TransactionalInterceptorRequired.java:97)
        ... 66 more

なんとなくロールバックしたことはわかりますが、NPEが投げられたことが原因とはわかりません。システムの保守をやっていると、『環境的な要因なのか』『入力が間違ってたのか』などの例外の原因がわからないと結構困ります。

なおしてみる

オープンソースなので、困ったらなおしてみます。バグ報告やパッチ投稿方法、ロギングの指針などコミュニティに関するルールはGlassFish Project - Community Rulesにまとまっています。

ソースのダウンロード

GlassFishソースコードSubversionで管理されています。とりあえずソースを確認したいだけなので、4.1タグのソースをsvn exportで持ってきます。

svn export https://svn.java.net/svn/glassfish~svn/tags/4.1
ソースコードを読む

例外のスタックトレースを改めて見ると、JTA実装であるJavaEETransactionImpl.javaの445行目において、commitを試みたが既にトランザクションロールバック確定とマーキングされていたので、RollbackExceptionを投げたとあります。

Caused by: javax.transaction.RollbackException: Transaction marked for rollback.
        at com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:445)

JavaEETransactionImpl.commitメソッドを見てみます。

com.sun.enterprise.transaction.JavaEETransactionImpl.commit()メソッド (445行目付近)

439    if ( isRollbackOnly() ) {
440      // rollback nonXA resource
441      if ( nonXAResource != null )
442        nonXAResource.getXAResource().rollback(xid);
443
444        localTxStatus = Status.STATUS_ROLLEDBACK;
445        throw new RollbackException(sm.getString("enterprise_distributedtx.mark_rollback"));
446    }

JavaEETransactionalImpl.commit()の445行目で、commit()実行時に既にjavax.transaction.Transaction.setTransactionRollback()メソッドの実行によって、ロールバックすべきとマーキングされていた場合、ロールバックの上、さらにRollbackExceptionがスローされています。

このjavax.transaction.RollbackExceptionのjavadocを見ると、RollbackExceptionには例外causeを引数に取るコンストラクタは定義されていないことに気づきます。例外スタックトレースにcauseが入ってこないのは、ここのコードが原因のようです。しかし、例外の原因を設定するコンストラクタがなければ、この部分を修正して対処することは難しいと思いました。

次に、そもそもランタイム例外であるNPEが投げられてロールバックが確定しているのに、何故コミットを実行しようとしているのかが気になりました。あえてJavaEETransactionalImpl.commit()を実行によってロールバックさせずに、最初からロールバックを実行すれば良いのではと。

そこで、コミットを呼び出しているコードを探してみます。

org.glassfish.cdi.transaction.TransactionalInterceptorRequired.transactionalメソッド

 69    @AroundInvoke
 70    public Object transactional(InvocationContext ctx) throws Exception {
         ... 途中省略
 91    Object proceed = null;
 92    try {
 93        proceed = proceed(ctx);
 94    } finally {
 95        if (isTransactionStarted)
 96            try {
 97                getTransactionManager().commit();
 98            } catch (Exception exception) {
 99                 String messageString =
100                "Managed bean with Transactional annotation and TxType of REQUIRED " +
101                        "encountered exception during commit " +
102                         exception;
103                 _logger.log(java.util.logging.Level.INFO,
104                    CDI_JTA_MBREQUIREDCT, exception);
105                 throw new TransactionalException(messageString, exception);
106           }
107   }

proceed(ctx)の中から例外が投げられても、問答無用でcommit()しています。

proceedメソッドの挙動が気になります。このメソッドは今確認したTransactionalInterceptorRequiredクラスの親クラスTransactionalInterceptorBaseクラスで定義されています。

org.glassfish.cdi.transaction.TransactionalInterceptorBase クラス

208     public Object proceed(InvocationContext ctx) throws Exception {
      ... 途中省略
224         Object object;
225         try {
226             object = ctx.proceed();
227         } catch (RuntimeException runtimeException) {
228             Class dontRollbackOnClass =
229                     getClassInArrayClosestToClassOrNull(dontRollbackOn, runtimeException.getClass());
230             if (dontRollbackOnClass == null) { //proceed as default...
231                 markRollbackIfActiveTransaction();
232                 throw runtimeException;
233             }

トランザクション境界内の処理からRuntimeExceptionが投げられた場合、@Transactional(dontRollbackOn=XXX.class)に設定されているロールバック対象外の例外でなければ、231行目でトランザクションロールバック対象とマークし、次の行でメソッドの中で発生した例外を再スローしています。

すなわち、現在の実装は例外が発生した時点ではロールバック対象としてマーキングして、例外が再スローされていますが、すぐその後に子クラスのTransactionalInterceptorRequiredクラスでcommit()が実行されているため、既にロールバック対象としてマーキング済によるコミット時例外によって、元の例外が上書きされていることによって、例外の原因がわからない事象が発生しているようです。

TransactionalInterceptorRequiredクラスの修正アイディア

@AroundInvoke
public Object transactional(InvocationContext ctx) throws Exception {
   ... 途中省略
Object proceed = null;
try {
    proceed = proceed(ctx);
} finally {
    if (isTransactionStarted) { 
        if (ロールバックマーク済み?) {
            getTransactionmanager().rollback();
        } else {
            try {
                getTransactionManager().commit();

上記のように、ロールバック対象としてマーキングされている場合は、コミットせずに最初からロールバックして、投げられた例外がコミット例外によって上書きされないように修正したいです。

スペック(JTA1.2)の確認

GlassFish4.1はJava EE7仕様を実装した参照実装です。コードを修正するには仕様に違反しないか注意が必要です。

今回の場合、今まではロールバック時にはRollbackExceptionが返されていましたが、修正後にはアプリから投げられたランタイム例外をそのまま投げることになります。トランザクション周りの仕様はJava Transaction API (JTA)で決まれている為、JCPのサイトから仕様のPDFを入手して読んでみます。

JTA1.2仕様をRollbackExceptionで検索しても、『ロールバック時には必ずRollbackExceptionを投げること』のような記述は見当たらないため、アプリのランタイム例外をそのまま@Transactionalを付与したメソッドの呼び出し元に返しても大丈夫そうです。

不安なのでWildFly8.2でも試してみますが、@Transactionalの中からランタイム例外を投げると、特にラップされずに返ってきます。

22:37:46,952 ERROR [io.undertow.request] (default task-2) UT005023: Exception handling request to /TransactionalTest-1.0-SNAPSHOT/rest/orders: org.jboss.resteasy.spi.UnhandledException: java.lang.NullPointerException: ぬるぽ
	at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:76) [resteasy-jaxrs-3.0.10.Final.jar:]
        ... 途中省略
Caused by: java.lang.NullPointerException: ぬるぽ
	at net.agetsuma.transactional.OrderRepository.persist(OrderRepository.java:24) [classes:]
	at net.agetsuma.transactional.OrderService.takeOrder(OrderService.java:26) [classes:]
ソースコード修正

最終的になおしてみたコードの.patchはGistにおいています。
patchコマンドで適用できます。

patch -p1 -d 4.1 < GLASSFISH-21172.patch

修正したソースコードGlassFish本流にパッチとして盛り込みをお願いする場合は、Oracle Contributor License (OCA)へのサインとオラクル社への送付が必要です。

修正したモジュールのビルド

GlassFish全体ビルドには時間が掛かるので、修正したモジュールのみビルドします。今回の対象モジュールはweld-integrationです。

cd 4.1/appserver/web/weld-integration
mvn package

GlassFish4.1はJDK7u9以上ででビルドします。JDK8でビルドすると、以下のようなメッセージが出力されて失敗します。

[WARNING] Rule 0: org.apache.maven.plugins.enforcer.RequireJavaVersion failed with message:
You need JDK greater or equal than 1.7.0-09 (JDK8 not supported yet)
モジュールの差し替え

新たに生成した weld-integration.jar を、元のファイルから差し替えます。

cp target/weld-integration.jar /home/test/work/glassfish4/glassfish/modules/weld-integration.jar 
統合テストの実行

GlassFishのソースにはQuicklook Testsと呼ばれる統合テストが含まれています。修正によって新たにバグを盛り込んでいないか確認したいので動かしてみます。
GlassFish Project - Community Rulesでは、maven runtestで動かせると書いてあります(mvnのこと?)。陳腐化しているようです。

試しに、普通にtestフェーズを指定して動かしてみます。テスト対象のGlassFishホームも合わせて設定してみます。

cd glassfish4/4.1/appserver/tests/quicklook
mvn -Dglassfish.home=/home/test/work/glassfish4/glassfish test
...
testng-summary:
     [echo]    [testng]
     [echo]    [testng] ===============================================
     [echo]    [testng] QuickLookTests
     [echo]    [testng] Total tests run: 120, Failures: 0, Skips: 0
     [echo]    [testng] ===============================================
     [echo]    [testng]

これで良いのか自信がないですが、テストをパスしたようです。

なおした結果

ロールバックの原因となった例外がそのままスローされるので、ロールバック原因がすぐわかるようになりました。

[2014-12-23T14:35:25.032+0900] [glassfish 4.1] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=28 _ThreadName=http-listener-1(2)] [timeMillis: 1419312925032] [levelValue: 900] [[
  StandardWrapperValve[org.netbeans.rest.application.config.ApplicationConfig]: Servlet.service() for servlet org.netbeans.rest.application.config.ApplicationConfig threw exception
java.lang.NullPointerException: ぬるぽ
    at net.agetsuma.transactional.OrderRepository.persist(OrderRepository.java:24)
    at net.agetsuma.transactional.OrderService.takeOrder(OrderService.java:26)
    ... 省略

まとめ

  • 試しにGLASSFISH-21172をなおしてみました。
  • なおしたコードはGistにおいてます
  • GlassFishオープンソースなので、誰でもソースが見れます。問題が起きても商用サーバならサポートに問い合わせるしかないですが、GlassFishなら解析する権利が誰にでも平等に与えられています。
  • Java EE がどう実装されているかコードを読むのはとても楽しいですね。