RESTEasy BeanValidationエラーメッセージのカスタマイズ
JAX-RS Specでは、BeanValidationのバリデーションエラー時には、エラー原因を返すことのみが規定されており、メッセージのフォーマット自体は実装依存です。
7.6 Validation and Error Reporting
In all cases, JAX-RS implementations SHOULD include a response entity describing the source of the error; however, the exact content and format of this entity is beyond the scope of this specification.
この記事ではRESTEasyの場合にどのようにメッセージフォーマットをカスタマイズするか言及します。
RESTEasyデフォルトの振る舞い
例として以下のバリデーションを実行を考えます。
public class Customer { @NotBlank(message = "Customer id is required.") private String id; @NotBlank(message = "Customer name is required.") private String name; @NotBlank(message = "Customer location is required.") private String location; ... } @Path("/customer") public class CustomerResource { @POST @Produces(MediaType.APPLICATION_JSON) @Consumes(MediaType.APPLICATION_JSON) public Customer post(@Valid Customer cu) { ... } }
WildFlyやQuarkusが内蔵するJAX-RS実装のRESTEasyの場合、バリデーションエラー時にはHTTPレスポンスヘッダにvalidation-exception:を含むと共に、以下のようなフォーマットのメッセージを返します。各プロパティはバリデーションの種類を示しています。例の場合はメソッドパラメータでバリデーションしているため、
trueparameterViolationsにメッセージが含まれています。
// 見やすいように改行を含めていますが、実際には改行は含まれません { "exception":null, "fieldViolations":[], "propertyViolations":[], "classViolations":[], "parameterViolations":[ { "constraintType":"PARAMETER", "path":"post.arg0.name", "message":"Customer name is required.", "value":"" }, { "constraintType":"PARAMETER", "path":"post.arg0.id", "message":"Customer id is required.", "value":"" } ], "returnValueViolations":[] }
エラーメッセージのカスタマイズ
もっとシンプルに以下のようなエラーメッセージのリストを返すことを考えます。
{"errors":["Customer id is required.","Customer name is required."]}
org.jboss.resteasy.api.validation.ResteasyViolationExceptionMapperクラスをオーバーライドするとメッセージフォーマットのカスタマイズができます。
コード例は以下の通りです。ResteasyViolationExceptionMapperクラスでは後で拡張できるように、いくつかのメソッドのスコープがprotectedに設定されています。WildFly17で動作します。Quarkus0.16.1では原因は詳しくデバッグしていませんが動作しません。
package sample; import org.jboss.resteasy.api.validation.ResteasyViolationException; import org.jboss.resteasy.api.validation.ResteasyViolationExceptionMapper; import org.jboss.resteasy.api.validation.Validation; import javax.json.Json; import javax.ws.rs.core.MediaType; import javax.ws.rs.core.Response; import javax.ws.rs.core.Response.ResponseBuilder; import javax.ws.rs.ext.Provider; import java.util.List; import java.util.stream.Collectors; @Provider public class ViolationExceptionMapper extends ResteasyViolationExceptionMapper { @Override protected Response buildViolationReportResponse(ResteasyViolationException exception, Response.Status status) { ResponseBuilder builder = Response.status(status); builder.header(Validation.VALIDATION_HEADER, "true"); if (isAcceptJson(exception.getAccept())) { builder.type(MediaType.APPLICATION_JSON); List<String> errors = exception.getViolations() .stream() .map(violation -> violation.getMessage()) .collect(Collectors.toList()); builder.entity(Json.createObjectBuilder() .add("errors", Json.createArrayBuilder(errors).build()) .build()); return builder.build(); } // Default media type. builder.type(MediaType.TEXT_PLAIN); builder.entity(exception.toString()); return builder.build(); } private boolean isAcceptJson(List<MediaType> accepts) { return accepts.stream() .anyMatch(mt -> MediaType.APPLICATION_JSON_TYPE.getType().equals(mt.getType()) && MediaType.APPLICATION_JSON_TYPE.getSubtype().equals(mt.getSubtype())); } }
org.jboss.resteasy.api.validationパッケージにクラスパスが通るように、pom.xmlのdependencyにresteasy-jaxrsを追加します。
<dependencies> <dependency> <groupId>org.jboss.spec</groupId> <artifactId>jboss-javaee-web-8.0</artifactId> <version>1.0.3.Final</version> <type>pom</type> </dependency> <dependency> <groupId>org.jboss.resteasy</groupId> <artifactId>resteasy-jaxrs</artifactId> <version>3.7.0.Final</version> <scope>provided</scope> </dependency> </dependencies>
まとめ
- JAX-RS仕様ではBeanValidationエラー時のメッセージフォーマットは規定されておらず実装依存
- RESTEasyの場合、エラー時にはHTTPレスポンスに
validation-exception : trueを含み、独自フォーマットのメッセージを返す - メッセージフォーマットのカスタマイズには
org.jboss.resteasy.api.validation.ResteasyViolationExceptionMapperの継承クラスを作る - 参考 RESTEasyドキュメント Chapter 55. Validation
OpenShiftでJBossクラスタを構成する仕組み
この記事は赤帽エンジニア Advent Calendar 2018の12/4分の記事です。
Red HatでJBoss EAPのサポートエンジニアをしています。自由なAdvent Calendarなので、自由に勉強メモを書いてみます。
JBossのようなAPサーバはクラスタメンバの探索に従来マルチキャストを使ってきましたが、OpenShift*1やk8sの環境が一般的になると、マルチキャストが使えないネットワークの方が多いです。
Red Hat Container Catalogで公開されているOpenShift向けのJBossコンテナイメージJBoss EAP CD for OpenShiftがどのようにクラスタを組んでいるかメモします。
EAP CDってなんぞやから、テストアプリケーションのデプロイ、クラスタディスカバリの仕組みDNS_PINGについて順を追って紹介します。
JBoss EAP CD for OpenShift
JBoss EAP Continuous Delivery for OpenShiftとは、2018年4月から3〜4ヶ月単位でリリースされている、OpenShift環境向けのEAPのバイナリです。今のところはTechnology Preview*2で、今後導入される予定のEAP新機能を先行して試す検証用を目的としています。EAP CDの3〜4つのリリースを組み合わせて、従来の同様にフルサポートされるEAPがリリースされるモデルとなっています。
従来のEAPと異なり、zip版はリリースされておらず、Red Hat Container Catalogを通じて、コンテナイメージをダウンロードする方式のみ提供されています。
デフォルトのプロファイルは standalone-openshift.xml であり、コンテナ起動時に /opt/eap/bin/launch に含まれるスクリプト類でstandalone-openshift.xmlをsedで色々置換して設定を作成する仕組みになっています。
OpenShiftがなくても、手元のDockerで起動してイメージの中身を確認できます。イメージにはbashが入っているので、通常のEAPとの差分については /opt/eap を見てみてください。
$ docker run --name eap-cd -p 8080:8080 registry.access.redhat.com/jboss-eap-7-tech-preview/eap-cd-openshift:14.0-4 $ docker exec -it eap-cd /bin/bash cd /opt/eap
テストアプリケーションのデプロイ
OpenShiftの環境があることを前提に、テストアプリケーションのデプロイをします。
eap-debug/session-test at master · n-agetsu/eap-debug · GitHubにある、簡単なセッションレプリケーションの動作確認用アプリです。
EAP CD向けのImageStreamとTemplateの登録
はじめにEAP CD向けの最新のImageStreamとTemplateをプロジェクト名 openshift に登録します。12/4時点ではEAP CD 14です。
$ oc project openshift $ for resource in eap-cd-image-stream.json eap-cd-amq-persistent-s2i.json eap-cd-amq-s2i.json eap-cd-basic-s2i.json eap-cd-https-s2i.json eap-cd-mongodb-persistent-s2i.json eap-cd-mongodb-s2i.json eap-cd-mysql-persistent-s2i.json eap-cd-mysql-s2i.json eap-cd-postgresql-persistent-s2i.json eap-cd-postgresql-s2i.json eap-cd-sso-s2i.json eap-cd-third-party-db-s2i.json eap-cd-tx-recovery-s2i.json; do oc replace --force -f https://raw.githubusercontent.com/jboss-container-images/jboss-eap-7-openshift-image/eap-cd/templates/${resource}; done
テンプレートによるアプリケーションのデプロイ
テンプレートeap-cd-basic-s2i を使ってセッションレプリケーションテスト用のアプリケーションをデプロイします。
$ oc new-app --template=eap-cd-basic-s2i -p IMAGE_STREAM_NAMESPACE=openshift -p SOURCE_REPOSITORY_URL="https://github.com/n-agetsu/eap-debug" -p SOURCE_REPOSITORY_REF="master" -p CONTEXT_DIR="session-test" -p APPLICATION_NAME="session-test"
テンプレートを実行すると、以下のような処理が行われます。
- https://github.com/n-agetsu/eap-debugをgit cloneして、eap-cd-openshiftイメージにソースコードを転送した上で、eap-cd-openshiftイメージに入っているMavenを利用してwarファイルをビルド。
- ビルドしたwarファイルを、eap-cd-openshiftイメージの /opt/eap/standalone/deployments に含めた、アプリケーションイメージを作成し、OpenShiftの内部レジストリにpush。eap-cd-openshiftのようにEAPのランタイムとMavenのようなビルドツールが入っているコンテナイメージを、OpenShiftではBuilder Imageと呼んでいて、Red Hat Container Catalogでは色々なBuilder Imageが公開されています。一方でBuilder Imageにビルド済みのwarファイルを追加して、Podとして起動するイメージをApplication Imageと呼んでいます。
- アプリケーションイメージのビルドが完了した後、DeploymentConfigの設定に沿ってアプリケーションイメージをPodとして起動。
アプリケーションイメージのPod起動が完了すると、以下のリソースが展開されます。ServiceやRouteなど、アプリケーションの動作に必要なリリースを個別に設定する必要はなく、テンプレートによって展開されます。
$ oc get all NAME READY STATUS RESTARTS AGE pod/session-test-1-build 0/1 Completed 0 31m pod/session-test-1-vldx2 1/1 Running 0 29m NAME DESIRED CURRENT READY AGE replicationcontroller/session-test-1 1 1 1 29m NAME TYPE CLUSTER-IP EXTERNAL-IP PORT(S) AGE service/session-test ClusterIP 172.30.133.229 <none> 8080/TCP 31m service/session-test-ping ClusterIP None <none> 8888/TCP 31m NAME REVISION DESIRED CURRENT TRIGGERED BY deploymentconfig.apps.openshift.io/session-test 1 1 1 config,image(session-test:latest) NAME TYPE FROM LATEST buildconfig.build.openshift.io/session-test Source Git@master 1 NAME TYPE FROM STATUS STARTED DURATION build.build.openshift.io/session-test-1 Source Git@5b856c7 Complete 31 minutes ago 1m53s NAME DOCKER REPO TAGS UPDATED imagestream.image.openshift.io/session-test docker-registry.default.svc:5000/cluster-test/session-test latest 29 minutes ago NAME HOST/PORT PATH SERVICES PORT TERMINATION WILDCARD route.route.openshift.io/session-test session-test-cluster-test.cloudapps.example.com session-test <all> edge/Redirect None ||< テンプレートの中身やパラメータの一覧を確認したい場合は、以下のコマンドで確認してください。 >|sh| $ oc get template eap-cd-basic-s2i -o yaml -n openshift
アプリケーションの動作確認
テストアプリケーションでは、アクセスカウンタと共に、アクセスされたホスト名を返しています。eap-cd-basic-s2i ではPodのレプリカ数は1で起動するため、毎回同じホスト名が返されます。
$ curl --insecure -c cookie.txt https://session-test-cluster-test.cloudapps.example.com/session-test/count count: 1, host: session-test-1-vldx2 $ curl --insecure -b cookie.txt https://session-test-cluster-test.cloudapps.example.com/session-test/count count: 2, host: session-test-1-vldx2 $ curl --insecure -b cookie.txt https://session-test-cluster-test.cloudapps.example.com/session-test/count count: 3, host: session-test-1-vldx2
Podのレプリカを2に増やしても、OpenShiftのRouterはデフォルトでソースIPベースのスティッキーセッションが有効化されているため、同じPodにアクセスし続けます。これではセッションレプリケーションが動いているかわからないため、レプリカ数を2に増やした後、元々アクセスしていたPodを削除してみます。
$ oc scale dc session-test --replicas=2 $ oc delete pod session-test-1-vldx2 $ curl --insecure -b cookie.txt https://session-test-cluster-test.cloudapps.example.com/session-test/count count: 4, host: session-test-1-fhvjs
別のホストにアクセスしましたが、HTTPセッションは継続しています。セッションレプリケーションがなければ、Podをdeleteした時点でセッションは失われていたでしょう。
OpenShiftのデフォルトではマルチキャストは飛びません。テンプレートの中ではStatefulSetを使ってホスト名を固定し、クラスタメンバを静的に定義することもしていません。テンプレートでデプロイすると、jgroupsのDNS_PINGの仕組みを使ってクラスタメンバの探索を行なっています。
JGroupsのDNS_PING機能
JGroupsにはk8s向けのクラスタディスカバリの実装として、KUBE_PINGとDNS_PINGの2種類の機能があります。コンテナイメージとしてはKUBE_PINGがデフォルトでstandalone-openshift.xmlに設定されていますが、テンプレートを利用するとコンテナ起動時にデフォルトでDNS_PINGに上書きします。
/opt/eap/standalone/configuration/standalone-openshift.xmlには、以下のようにJGroupsサブシステムの設定にopenshift.DNS_PINGが含まれます。
<subsystem xmlns="urn:jboss:domain:jgroups:6.0"> <channels default="ee"> <channel name="ee" stack="tcp"/> </channels> ... <stack name="tcp"> <transport type="TCP" socket-binding="jgroups-tcp"> <property name="use_ip_addrs">true</property> </transport> <protocol type="openshift.DNS_PING" ></protocol> <protocol type="MERGE3"/>
KUBE_PINGはざっくり言うと、k8sのAPIサーバに同じラベルを持つPodのリストを問い合わせてクラスタメンバを見つけています。OpenShift上でKUBE_PINGを動作させようとすると、 アプリケーションからk8sのREST APIへのアクセスを許可する設定が必要ですが、DNS_PINGではOpenShift側の設定は不要なためシンプルに使えます。
DNS_PINGの仕組み
ここまで長くなりましたが、ここからが今日のタイトルの話です。
DNS_PINGはOpenShift上のDNSサーバのSRVレコードの仕組みを使って、クラスタメンバを見つけています。実際にレコードを内容を見てみると想像が付きやすいので、OpenShift上の任意のノードにSSHログインしてnslookupしてみます。
$ nslookup -type=SRV _tcp.session-test-ping.cluster-test.svc.cluster.local Server: 192.168.122.2 Address: 192.168.122.2#53 _tcp.session-test-ping.cluster-test.svc.cluster.local service = 10 50 8888 fd149e20.session-test-ping.cluster-test.svc.cluster.local. _tcp.session-test-ping.cluster-test.svc.cluster.local service = 10 50 8888 14a2d9.session-test-ping.cluster-test.svc.cluster.local.
ホスト名のようなものが出てくるため、pingしてみます。
$ ping fd149e20.session-test-ping.cluster-test.svc.cluster.local. PING fd149e20.session-test-ping.cluster-test.svc.cluster.local (10.130.0.11) 56(84) bytes of data. 64 bytes from 10.130.0.11 (10.130.0.11): icmp_seq=1 ttl=64 time=1.51 ms
oc get pod -o wideで確認すると、SRVレコードで取得できたFQDNfd149e20.session-test-ping.cluster-test.svc.cluster.local.はPodのIPアドレス10.130.0.11とわかります。
$ oc get pod -o wide NAME READY STATUS RESTARTS AGE IP NODE NOMINATED NODE session-test-1-build 0/1 Completed 0 1h 10.130.0.9 node01.openshift.example.com <none> session-test-1-vldx2 1/1 Running 0 1h 10.130.0.11 node01.openshift.example.com <none> session-test-1-xmqpc 1/1 Running 0 41m 10.130.0.12 node01.openshift.example.com <none>
k8sの機能として、ロードバランシング用のCluster IPを持たない(clusterIP: none) Headless Serviceがデプロイされた場合、Serviceに関連づけられたPodのホスト名とServiceが公開しているポート番号を、k8s内部のDNSのSRVレコードに登録する仕組み*3があります。
OpenShiftのテンプレートでは、EAP-CD(eap-cd-basic-s2i)向けだけに止まらず、EAP64やEAP71のイメージにおいても、HTTPアクセスのためのServiceとは別に、以下のようなクラスタディスカバリ向けのServiceを登録しています。
$ oc get svc session-test-ping -o yaml apiVersion: v1 kind: Service metadata: ... spec: clusterIP: None ports: - name: ping port: 8888 protocol: TCP targetPort: 8888 selector: deploymentConfig: session-test sessionAffinity: None type: ClusterIP
もう一度nslookupの例に戻ります。
$ nslookup -type=SRV _tcp.session-test-ping.cluster-test.svc.cluster.local ... _tcp.session-test-ping.cluster-test.svc.cluster.local service = 10 50 8888 fd149e20.session-test-ping.cluster-test.svc.cluster.local. _tcp.session-test-ping.cluster-test.svc.cluster.local service = 10 50 8888 14a2d9.session-test-ping.cluster-test.svc.cluster.local.
nslookupのクエリ対象である、_tcp.session-test-ping.cluster-test.svc.cluster.localは、前述のService session-test-ping の追加によって登録されたDNSレコードです。k8sのServiceを追加すると、今のような命名規則でSRVレコードが追加されます。
<Serviceのprotocol>.<Service名>.<プロジェクト名(namespace)>.svc.cluster.local
SRVレコードは以下のような情報を含んでいます。PriorityとWeightはSRVレコードを読み取るクライアントが、負荷分散の重み付けのために使う情報です。DNS_PINGは負荷分散ではなく単純にクラスタディスカバリにしかSRVを使っていないため、現時点での実装では重み付け情報は使っていません。SRVレコードのポート番号も現時点での実装では使っていません。クラスタ間通信にはデフォルトで7600ポート(TCP)が使われます。
service = 10 50 8888 fd149e20.session-test-ping.cluster-test.svc.cluster.local.
= (Priority) (Weight) (ポート番号) (ホスト名)このようにJGroupsはSRVレコードからクラスタメンバの情報を取得しています。一度メンバの探索ができたら、その後FDとFD_ALLで定期的にヘルスチェックを行い障害検知を行うのは、従来のTCPユニキャストベースのクラスタと同じです。
このDNS_PINGのソースコードは以下にあります。
GitHub - jboss-openshift/openshift-ping: JGroups PING protocols for OpenShift
今回のテンプレートeap-cd-basic-s2iのように、テンプレートでは必要な関連リソースを一緒にデプロイしてくれるため、慣れないと中身で何やっているかわからない不安はありますが、テンプレートを使う方がハマりにくいです。
おそらく初めてEAPをOpenShiftにデプロイするときに、テンプレートなしでJGroups向けのHeadless Serviceのデプロイに思い当たる人はなかなかいないと思います。プロジェクト固有のテンプレートが必要な場合、まずは既存のテンプレートで慣れてから、テンプレート作成に着手した方が近道だと思います。
まとめ
- JBoss EAP CD for OpenShiftは従来のEAPと比較してインクリメンタルなモデルでリリースしている、コンテナイメージ形式リリースのバイナリです。今のところTechnology Previewのため評価検証向けです。
- JBoss EAP CD for OpenShiftの最新版をOpenShiftで利用するためには前述の通りImageStreamとTemplateの更新をします
- マルチキャストが使えない環境のために、DNS_PINGと呼ばれる、Headless ServiceによるSRVレコードの参照により、クラスタを構成しています
- 慣れないうちはテンプレートを使うのがおすすめです
明日は@orimanabuさんです、お楽しみに！
*1:OpenShiftの場合デフォルトから設定変えるとマルチキャストは使える Managing Networking | Cluster Administration | OpenShift Container Platform 3.11
*2:Technology Previewの詳細は Technology Preview Features Support Scope - Red Hat Customer Portal を参照
コネクションプールの挙動差分によるバグ顕在化
この記事は Java EE Advent Calendar 2016の12/2分の記事です。
明日は@opengl_8080さんです。
Java EEが使われているシステムは、改修を加え続けながら数年〜十年と運用し続けるライフサイクルの長いシステムが多くあります。
アプリケーションを全面刷新することはなくても、ハードウェアやOS、ミドルウェアのEOSLを契機にJava EEサーバのバージョンを上げる、いわゆる『更改』という作業は色々な所で行われていると思います。
更改で厄介なのは、OSやミドルウェアのリリースノートや非互換ガイドに記載されていない『些細なバージョン間差分』です。本来であれば些細なバージョン間差分はアプリケーションの振る舞いに影響を与えないものですが、モノによってはバグを顕在化させ、たまたま動作していたものが、バージョンアップすると動かなくなったり、リソースリークを発生させたりします。
コネクションプールの些細な挙動差分による、バグ顕在化の例を以下にまとめます。
WildFlyバージョン間のコネクションプール挙動差分
データソースからコネクションを取得する良くあるコードを考えます。
DataSource ds = ...; try (Connection conn = ds.getConnection()) { System.out.println(conn); // SQLの実行...
WildFlyはバージョンにより、コネクションプールの払い出しポリシーが異なります。
- FIFO(First In First Out)
- プールに返されたコネクションから再払い出し
- 古いコネクションがプールの残るため、一定時間アイドル後の切断設定(idle-timeout-minutes)により切断されやすい
- FILO(First In Last Out)
- 前回の払い出しから最も時間の経っているコネクションから再払い出し
- idle-timeout-minutesの契機で切断されにくい
| バージョン | コネクションプールの払い出しポリシー | |
|---|---|---|
| JBoss AS 7.1.1 | FIFO | |
| WildFly 8.x | FILO | |
| WildFly 9.0.0〜9.0.1 | FIFO | |
| WildFly 9.0.2 | FILO | |
| WildFly 10.x〜 | FILO | |
| 参考: Tomcat8.5.x (DBCP) | FIFO (lifo=falseの追加によりFILOに変更可能) | |
| 参考: Tomcat8.5.x (Tomcat JDBC) | FIFO |
通常はプールの払い出し順序が変わっても、アプリケーションの振る舞いに影響はありません。払い出し順序はJava EE仕様や実装製品固有の仕様で規定されているものでもないため、特定の払い出し順序を期待すること自体、あまり良くないことです。
しかし、APサーバと連携するDBサーバのリソースリークや、アプリケーション自体の潜在的な問題を露にさせることもあります。
PostgreSQL側のメモリリークが顕在化
PostgreSQLには以下で紹介されているように、create temporary tableとdrop temporary tableを同一セッションで繰り返すと、メモリリークする不具合があります。
Memory leak in PL/pgSQL function which CREATE/SELECT/DROP a temporary table
psコマンドで該当のセッションに対応するプロセスのRSSをモニタリングすると徐々に上がっていきます。
# コネクションごとのステータスが書かれている子プロセスのRSSが徐々に上がる USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND postgres 5994 0.0 0.2 338948 4004 ? Ss 07:21 0:00 postgres: postgres test 127.0.0.1(59780) idle
コネクションプールの最小値と最大値を一般的に推奨される同一値に設定したJBoss AS7を、最新のWIldFly10.x系にバージョンアップすると、このメモリリークが顕在化しやすくなります。
JBoss AS7のプール払い出しポリシーはFIFOのため、古いコネクションがプール中に残りやすく、idle-timeout-minutesに到達して定期的に切断され、PostgreSQL側はセッションの終了と共にメモリが解放されます。
一方、WildFly10.x系ではFILOのため、プール中のコネクションは均等に払い出され、アイドル時間が短くなる傾向になります。idle-timeout-minutesに引っかかるコネクションが減り、結果的にPostgreSQL側でセッションごとの子プロセス終了が発生しにくく、メモリリークが顕在化しやすくなります。
対処
WildFlyには設定によってプールの払い出し順序を変更するオプションがあります。
WildFly10.xおよびJBossEAP7.xの場合
JBoss CLIで以下のように設定すると、プール払い出しポリシーがデフォルトのFILOからFIFOに変更されます。
/subsystem=datasources/data-source=データソース名:write-attribute(name=capacity-decrementer-class,value=org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutFIFODecrementer)
上記のCLIはstandalone-xxx.xmlにcapacityの子要素として反映されます。
<datasource jndi-name="java:jboss/jdbc/testDS" pool-name="testDS" enabled="true"> <connection-url>jdbc:postgresql://localhost:5432/test</connection-url> ... <capacity> <decrementer class-name="org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutFIFODecrementer"/> </capacity>
JBoss EAP 6.4.2 以降の場合
有償版のJBoss EAP 6.4系のデフォルトのプール払い出しポリシーはFILOですが、以下のissueによりFIFOに変更できるオプションが6.4.2より追加されています。
[JBJCA-1260] Allow System Property to override default First In First Out (FIFO) pooling behavior - JBoss Issue Tracker
プール払い出しポリシーをFIFOに変更するためには、Javaシステムプロパティに ironjacamar.filo_pool_behavior=true を設定します。
$JBOSS_HOME/bin/standalone.conf
if [ "x$JAVA_OPTS" = "x" ]; then JAVA_OPTS="-Xms1303m -Xmx1303m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true" ... JAVA_OPTS="$JAVA_OPTS -Dironjacamar.filo_pool_behavior=true"
トランザクション設定のミスが顕在化
プールの払い出し順序の変更は、アプリケーションの潜在的なバグを顕在化させ、処理が正常に動作しない事象を引き起こすこともあります。
以下の例はSpringの誤ったトランザクションの設定例です。本来は同一トランザクションでSELECT ... FOR UPDATEによる悲観ロックの取得と更新を実行したいところです。以下のコードでは、privateメソッドに設定された@Transactionalは意味がなく、lock()メソッドとupdate()メソッドは別々のトランザクション、別々のDBコネクション(DBセッション)で動作します。しかし、プールの挙動がFIFOであるJBoss AS7以前にデプロイして動作させると、並行リクエストがない低負荷な状態ではプールに返した直後のコネクションが再度払い出されるため、擬似的にトランザクションが継続したのと同様に振る舞います。
WildFlyのバージョンを上げると、続けて実行されたDataSource.getConnection()が同一のコネクションを返さなくなる為、ロックを取得した状態のコネクションが再取得されません。既に別コネクションで悲観ロックが取得されているため、UPDATE文はロック待ちとなり、タイムアウトまで一時的にハングアップしたように見えます。
@Service public class SampleService { public void doSomething() { lock(); update(); } @Transactional private void lock() { // 悲観ロックの取得 // Connection conn = dataSource.getConnection(); // SELECT ... FOR UPDATE } @Transactional private void update() { // ロックしたレコードの更新 // Connection conn = dataSource.getConnection(); // UPDATE ... SET ... } }
対処
これは単純にアプリケーションのミスであるため、アプリケーションを改修します。
@Service public class SampleService { @Transactional public void doSomething() { lock(); update(); } private void lock() {...} private void update() { ... } }
MavenのJAX-WSプラグイン
まだまだエンタープライズな分野ではJAX-WSがシステム間連携に使われることが多い。wsdlからスタブを生成するMavenプラグインの使い方に関するメモ。
JAX-WS Mavenプラグイン
https://jax-ws-commons.java.net/jaxws-maven-plugin/ にJAX-WSの参照実装Metroの一部として提供されている。最新バージョンは2.3。
pom.xml の書き方
wsimport (wsdlからスタブコード生成) の例。設定可能なパラメータの一覧より、よく使う部分だけ以下に記載する。
<?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>net.agetsuma</groupId> <artifactId>SOAPClient</artifactId> <version>1.0-SNAPSHOT</version> <packaging>jar</packaging> <properties> <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding> <maven.compiler.source>1.8</maven.compiler.source> <maven.compiler.target>1.8</maven.compiler.target> </properties> <build> <plugins> <plugin> <groupId>org.jvnet.jax-ws-commons</groupId> <artifactId>jaxws-maven-plugin</artifactId> <version>2.3</version> <executions> <execution> <goals> <goal>wsimport</goal> </goals> </execution> </executions> <configuration> <!-- .wsdlの格納ディレクトリ。デフォルト ${basedir}/src/wsdl --> <!-- <wsdlDirectory>src/main/wsdl</wsdlDirectory> --> <!-- スタブ生成対象のwsdlファイル名。wsdlDirectory配下のファイル名を指定。 定義がなかった場合はwsdlDirectory配下すべての.wsdlが対象 --> <!-- <wsdlFiles> <wsdlFile>HelloWorld.wsdl</wsdlFile> </wsdlFiles> --> <!-- 中間生成ファイルを保持するか。具体的にはスタブのソースコードのこと。 デフォルトはfalseで.classファイルのみ生成する。 --> <keep>true</keep> <vmArgs> <vmArg>-Djavax.xml.accessExternalSchema=all</vmArg> </vmArgs> </configuration> </plugin> </plugins> </build> </project>
このプラグインはデフォルトでフェーズgenerate-source (コンパイルする前) *1 に動くため、中間生成ファイルとして出力されるソースコードは破棄しても問題ないが、デバッグ目的で生成しておくと便利。
JDK8ではvmArgsの設定がないと例外が出て動かない。詳細についてはNetBeansのBug 241570や、このMavenプラグインのJIRA JAX_WS_COMMONS-129で紹介されている。
ビルド
いつも通りmvn packageでビルドできる。
mvm clean package
クラスローダリークとヒープダンプ
Java EE を使っている人なら多くの人が遭遇するクラスローダリーク。EclipseなどのIDEでホットデプロイしながら開発していると、突然APサーバから応答がなくなったり、java.lang.OutOfMemory : PermGenが出力されたりする。
原因についてはnekopさんのスライドやyamadanさんのブログに紹介されているので、ここではクラスローダリークを手元で再現させてみて、どのようなヒープダンプになるか紹介する。
ヒープダンプの解析にはEclipseMemoryAnalyzer(MAT)を使う。
1. Duplicate Classes を確認する
クラスローダリークが発生している状況では、同一のクラスが異なるクラスローダよりロードされている事象が起こっている。MATでは重複クラスロードの一覧を表示する機能があるため、1クリックで確認できる。
2. Paths to GC Roots の確認
ここまででクラスローダリークかどうかを識別したが、原因がわからない。何が原因でGCされていないかは、対象のクラスローダインスタンスを選択して右クリックし、Path to GC Rootsを確認する。
以下のように、TomcatのプールされているTaskThreadが持つThreadLocalから参照されてGCされないことがわかる。
WildFly8でも同様に、プールされているスレッドのThreadLocalから参照されてGCされないことがわかる。
ThreadLocalにユーザ情報などリクエスト共通で使いたいデータを格納した後、ThreadLocal.remove()を実行せずにAPサーバのプールにスレッドを返す、よくあるクラスローダリークの原因例を示したヒープダンプでした。ServletFilterなどを使ってタスクスレッドがAPサーバのプールに返る前にThreadLocal.remove()で掃除することが大切です。
EJBタイマーサービスを使う
定番のスケジュール実行としてはcronがあるが、Java EEにおいても同様の機能が用意されている。Java EE 5以前では『x秒後に実行する』ような機能しかなかったが、Java EE 6(WLS12c/JBossEAP6など)以降ではcron風にカレンダー形式で設定ができる。
使い方
Java EE 6から導入されたアノテーションによるタイマー設定と、従来からあるAPIによるタイマー設定の両方を紹介する。
@Scheduleによるタイマー設定
昔のcron.dailyのように、毎日4時2分に動かしたい場合。
@Scheduleを付与したメソッドが、対象の時間になるとコールされる。EJBなので、timeout()メソッドはトランザクション・コンテキスト内として実行される。
import javax.ejb.Schedule; import javax.ejb.Singleton; @Singleton public class ScheduleTimer { @Schedule(hour="4", minute="2") public void timeout() { System.out.println("timeout occur."); } }
毎分、0秒と30秒に呼び出したい場合。*/30で30秒ごとを示す。例えばsecond="*/10"とした場合は、毎分の10秒/20秒/30秒…のように10秒ごとに呼び出すことも可能。
@Schedule(hour="*", minute="*", second="*/30")
毎週土曜日の04時02分。
0=日曜日とした数値による指定もできるが、文字列の方がわかりやすい。Sun, Mon, Tue, Wed, Thu, Fri, Satのいずれかで指定できる。
@Schedule(dayOfWeek="Sat", hour="4", minute="2")
毎分10秒と30秒に呼び出したい場合。
カンマを使って複数の条件を記載する。
@Schedule(hour="*", minute="*", second="10,30")
他の例はJava EE6のチュートリアルにも詳しく解説されている。
APIによるタイマー設定
x秒後に1回だけ実行
Java EE 5の頃からあるcreateTimerメソッドによる設定。10000ミリ秒後(10秒後)に1回だけ、@Timeoutで定義したタイムアウト処理を実行する。タイマーにはSerializable実装のインスタンスをパラメータとして渡すこともでき、この例ではStringの"hello world"を渡している。
import javax.annotation.PostConstruct; import javax.annotation.Resource; import javax.ejb.Singleton; import javax.ejb.Startup; import javax.ejb.Timeout; import javax.ejb.Timer; import javax.ejb.TimerService; @Singleton @Startup public class HelloTimer { @Resource private TimerService timerService; @PostConstruct public void setTimer() { // 10秒後に1回だけタイムアウト処理をする timerService.createTimer(10000, "hello world"); } @Timeout public void handleTimeout(Timer timer) { String msg = (String) timer.getInfo(); System.out.println("Timeout: " + msg); } }
x秒間隔で繰り返し実行
Java EE6では、APIによるタイマ設定も強化されていて、インターバル設定によるタイマ定義もできる。以下の例では、0秒後をカウントスタートにして、10秒に1回タイムアウト処理を呼び出す。createTimerメソッドと異なり、タイムアウト処理に渡したい情報はjavax.ejb.TimerConfigクラスにラップして渡す。
TimerConfig timerConfig = new TimerConfig(); timerConfig.setInfo("hello world"); timerService.createIntervalTimer(0, 10000, timerConfig);
スケジュール実行をAPIで指定する
@Scheduleで定義できるスケジュール実行は、APIでも定義することができる。
以下の例では毎分10秒に@Timeoutで定義されたタイムアウトメソッドが呼び出される。
TimerConfig timerConfig = new TimerConfig(); timerConfig.setInfo("hello world"); ScheduleExpression schedule = new ScheduleExpression(); schedule.hour("*"); schedule.minute("*"); schedule.second("*/10"); timerService.createCalendarTimer(schedule, timerConfig);
他にもいろいろあるが、TimerServiceインタフェースのJavaDocに解説がある。
はまりどころ
Java EEのチュートリアルからは読み取れない、実際に触ってみて思ったいくつかのはまりどころを以下にまとめる。
はまりどころ1 『リトライ』
EJB3.2(Java EE7)仕様では、タイマー呼び出し先のメソッドで例外が投げられても、少なくとも1回はリトライしてくださいと定義してある。
13.4.3 Timer Expiration and Timeout Callback Method
http://download.oracle.com/otndocs/jcp/ejb-3_2-fr-eval-spec/index.html
If the transaction fails or is rolled back, the container must retry the timeout at least once.
これはEJB3.1(Java EE6)でも同様の記載がある。WildFly8.0.0.Finalで試すと、タイムアウトメソッドからランタイム例外を投げると以下のようなログが出力され、1回のみリトライされる。
14:59:27,461 INFO [org.jboss.as.ejb3] (EJB default - 1) JBAS014121: Timer: [id=353403aa-c950-4aae-b6ba-656076e2bcc1 timedObjectId=Timer-1.0-SNAPSHOT.Timer-1.0-SNAPSHOT.HelloTimer auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@39f8f1b0 initialExpiration=Sun Apr 27 14:59:27 JST 2014 intervalDuration(in milli sec)=0 nextExpiration=null timerState=IN_TIMEOUT info=hello world will be retried 14:59:27,462 INFO [org.jboss.as.ejb3] (EJB default - 1) JBAS014123: Retrying timeout for timer: [id=353403aa-c950-4aae-b6ba-656076e2bcc1 timedObjectId=Timer-1.0-SNAPSHOT.Timer-1.0-SNAPSHOT.HelloTimer auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@39f8f1b0 initialExpiration=Sun Apr 27 14:59:27 JST 2014 intervalDuration(in milli sec)=0 nextExpiration=null timerState=IN_TIMEOUT info=hello world
タイムアウト処理はトランザクション内のため、DBMSへのアクセスは例外時にロールバックされるが、ファイルシステムにアクセスしてCSVファイルを編集したり、ディレクトリを作ったり消したりする場合は自分で例外処理を書かないと戻らないので注意が必要。
はまりどころ2 『タイマーの永続化』
各タイマーはデフォルトで永続化される。WildFly8.0.0.Finalではデフォルトで${WILDFRY_HOME}/standalone/data/timer-service-dataにファイル形式で永続化されている。ドキュメントは見当たらなかったが、DBMSを永続化先に設定することもできるようだ。
永続化されたタイマーは、APサーバを一旦停止して、再起動したあとにも引き継がれる。例えば、30秒後にタイマーを設定し、30秒経つ前にAPサーバを停止、しばらくしてから再起動すると、再起動時点でタイマー設定時より30秒以上経過していた場合、すぐにタイムアウト処理が実行される。
タイマー永続化は明示的に再実行しなくても良い反面、少し怖い面もある。
例えば、夜に動いて欲しいバッチ処理をデフォルト通り永続化されたタイマーで設定していた場合、トラブル等で夜間に一時的に停止していて、日中になってから再起動した時、意図せず日中にバッチ処理が動き始めてしまうことも考えられる。
@Scheduleを使っている場合は、以下のようにpersistent="false"を設定することで、永続化が無効となる。
@Schedule(hour="4", minute="2", persistent="false")
APIでも、TimerConfigに永続化有無を設定することができる。
// コンストラクタの第2引数で永続化有無を設定。falseは無効。デフォルトtrue。 TimerConfig timerConfig = ("hello world", false); timerService.createIntervalTimer(0, 10000, timerConfig);
はまりどころ3『EJB実行スレッドが足りない』
APサーバの実装にもよるが、少なくともWildFly8およびJBossEAP6は、タイムアウト処理はEJB処理用のスレッドプールからスレッドを払い出して処理を行う。デフォルト値は10であるため、10を超える並列数でタイムアウト処理を走らせようとすると、スレッド空き待ちになる可能性がある。
並行で動かしたいタイムアウト処理が多くなる場合はチューニングした方が良いと思う。
EJBスレッド数は管理コンソールでは以下のような画面から確認できる。
[Profile] -> [Subsytems] -> [Container] -> [EJB 3] -> [THREAD POOLS]
管理コンソールでそのまま変更しても良いし、以下のようにCLIから変更することもできる。
[standalone@localhost:9990 /] /subsystem=ejb3/thread-pool=default:write-attribute(name=max-threads,value=50)
はまりどころ4 『EJBプール数が足りない』
タイムアウト処理が大量に並行動作させるケースでは、スレッドだけでなくStatelessSessionBeanのプール数にも注意する必要がある。
EJB仕様ではEJB2.xの頃より、StatelessSesionBeanのインスタンスに対する並行アクセスを許可していない。代わりにEJBをプールしつつで1スレッドごとに1つのインスタンスを割り当てる実装としている。
4.3.13 Serializing Session Bean Methods
http://download.oracle.com/otndocs/jcp/ejb-3_2-fr-eval-spec/index.html
The container serializes calls to each stateful and stateless session bean instance. Most containers will support many instances of a session bean executing concurrently; however, each instance sees only a serialized sequence of method calls.
WildFly8の場合、デフォルトでは要求に応じてその都度EJBインスタンスを生成するが、JBossEAP6.2の場合はEJBプール数に上限があり、デフォルトは20である。多くの場合、普通のオンライン処理でも並行数20では足りないので、100ぐらいまで広げてみても良いと思う。
EJBスレッド数は管理コンソールでは以下のような画面から確認できる。
[Profile] -> [Subsytems] -> [Container] -> [EJB 3] -> [BEAN POOLS]
管理コンソールでそのまま変更しても良いし、以下のようにCLIから変更することもできる。
[standalone@localhost:9999 /] /subsystem=ejb3/strict-max-bean-instance-pool=slsb-strict-max-pool:write-attribute(name=max-pool-size,value=100)
トラブルに備えるJVMオプション
以前の記事でトラブルが起きた後の初動対応を書いてみたが、いざトラブルに遭遇すると、まず再起動してからどうするか考えるケースが多いと感じている。しかし何も情報がないと『情報がない/再現方法が不明』などの理由からそのままお蔵入りになってしまう。今回はトラブルに事前に備えるために、地味だけど大切なJavaVMのオプションをまとめてみる。
- GCログの出力とローテーション
- OutOfMemoryError発生時のヒープダンプ自動出力と出力パス設定
- JavaVMクラッシュログの出力パス設定
JVMオプションの設定 (OpenJDK/OracleJDK)
JavaVMにはGCおよびヒープメモリの状態をロギングする仕組みや、OufOfMemoryError時にヒープダンプを自動的に出力するような障害に備えて自動的に情報を出力する機能がある。おすすめのオプション*1は以下の通り。
java -Xms?g -Xmx?g -XX:MaxPermSize=?m (JDK8は-XX:MaxMetaspaceSize=?m) -Xloggc:/home/test/wildfly-8.0.0.Final/standalone/log/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/test/wildfly-8.0.0.Final/standalone/log/ -XX:ErrorFile=/home/test/wildfly-8.0.0.Final/standalone/log/hs_err_pid%p.log
GCログの取得
前回にも書いたが、JDK6u34/JDK7u2より-XX:+UserGCLogFileRotationによりGCログのローテーションが可能になっている。例では、-XX:NumberOfGCLogFiles(ファイル数)を5、-XX:GCLogFileSize(サイズがいくつになったらローテーション)を10MBに設定している。
また、-XX:+PrintGCDateStampsもとても便利な設定。デフォルトではJavaVMの起動時間から経過秒数のみログに出力されるが、このオプションを設定すると日付形式で以下の1番左のレコードのように出力してくれる。
2014-03-30T16:58:11.048+0900: 5.114: [Full GC2014-03-30T16:58:11.048+0900: 5.114: [Tenured: 1675K->16783K(349568K), 0.1214210 secs] 95380K->16783K(506816K), [Perm : 26686K->26686K(26688K)], 0.1215920 secs] [Times: user=0.12 sys=0.00, real=0.12 secs]
取得したログのグラフ化にはGCViewerがとても便利。GitHubでメンテナンス続けられている最新版ではjarを配ってないようなので、ソースを取得してmavenでビルドする。
cd GCViewer-1.33 mvn clean package
targetディレクトリ配下にビルドされたGCViewerができるので、java -jar gcviewer-1.33.jarで起動する。簡単なサンプルプログラムに対してgatling使って負荷を掛け続けたときのGCログ表示例を示す。
様々な色があるが、一番大切なのは青の線が示すUsed Heap(使用ヒープ量)で、このテストアプリではGC後に安定して下がっているので問題ない。メモリリークの傾向があるときは、この青い線がどんどん上がっている傾向が見える。
-XX:+HeapDumpOnOutOfMemoryErrorの設定
HeapDumpOnOutOfMemoryErrorを設定すると、OutOfMemoryErrorが発生したタイミングで、自動的にヒープダンプを取得してくれる。出力先パスは何も指定しないとJavaを起動したカレントディレクトリになるので、-XX:HeapDumpPathを明示的に取得して、アプリケーションサーバのログディレクトリを指定すると情報が一カ所に集まって便利。
このオプションを設定した状態でOutOfMemoryErrorを発生させると、以下のようなメッセージが出力される(JDK7u51の場合)。
java.lang.OutOfMemoryError: Java heap space Dumping heap to /home/test/wildfly-8.0.0.Final/standalone/log/java_pid4167.hprof ... Heap dump file created [249928359 bytes in 0.848 secs]
HeapDumpPathで指定したディレクトリにjava_pid<pid>.hprofの名前でヒープダンプが出力されているのがわかる。
余談だが、OutOfMemoryErrorはユーザのプロセス生成数上限(ulimit -u)に達してネイティブスレッドが生成できなくなったときにもスローされるが、この場合はヒープダンプは出力されない。プロセス生成数上限に達した場合は以下のようなメッセージが出力される。
Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread
at java.lang.Thread.start0(Native Method)
at java.lang.Thread.start(Thread.java:713)CentOS6.5では一般ユーザのプロセス数上限が1024であり、スレッドもこの上限の範囲となるが、このエラーが発生したときは、何らかの要因により終わらなくなったスレッドが多く残っていることが考えられるので、プロセス生成数上限を拡大しても問題が解決しない場合も多いと思う。
-XX:ErrorFileの設定
JNIで呼び出した自作ライブラリにバグがあったり、JavaVM自体の不具合を踏んだりするとJavaプロセスがクラッシュしてエラーファイルを出力してくれる。この機能はヒープダンプと異なりデフォルトで有効であるが、出力先を集約したい場合は明示的に設定する必要がある。今回の例ではアプリケーションサーバのログディレクトリを出力先としている。
動作中のWildFly8に kill -s SIGSEGV pid すると以下のようなファイルが出力される。
# A fatal error has been detected by the Java Runtime Environment: # # SIGSEGV (0xb) at pc=0x0000003d7300822b, pid=9731, tid=140160209254144
プロセスがクラッシュした原因、クラッシュ時のレジスタ内容、リンクしていた動的ライブラリ(.so)、/proc/meminfoや/proc/cpuinfoなどのマシン情報も含まれているため、これを見るとJDKのJIRAを検索して既知のバグを踏んだかどうかはある程度切り分けられる。
読み方についてはOracle社が公開しているTroubleshooting Guide for HotSpot VMにて解説されている。
まとめ
*1:ヒープサイズの設定やGCストラテジの選択についてはアプリケーションにより異なるので、ここでは言及しない。Java Performanceにヒープサイズの決定プロセスが詳しく書いてあったので、参考になると思う。
