PayaraのJMX Monitoring Service
この記事は Payara Advent Calendar 2016の12/23分の記事です。
昨日はsuke_masaさんのPayaraのバグを報告してみようでした。
明日は@yumix_hさんです。
2016/8/1にリリースされた Payara Server 4.1.1.163 より、指定したJMX MBeanの値を定期的にロギングできるJMX Monitoring Serviceが追加されました。
多くのAPサーバではJMX経由でリクエストスレッドプールや、JDBCコネクションプールなどの枯渇すると重大なトラブルに絡むことを多いメトリクスを収集できますが、jconsoleでは最新値を見れるだけなので事後障害解析には役立ちません。障害解析には虚無僧を使ってロギングしたり、jolokiaを追加してHTTP-API経由によるLogstashやFluentdで定期的に収集した値が必要です。
Payaraは虚無僧を加えなくてもJMX MBeanの値のロギングが可能です。
JMX Monitoring Serviceの使い方
Payaraの公式ドキュメントにはJavaヒープメモリ使用量の例が記載されています。
しかし、ヒープメモリのロギングであればGCログ(-Xloggc:gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps)の方がより詳細な情報が取得できます。JMXに期待するのはヒープ以外のメトリクスです。
GlassFishの頃より、PayaraにはMonitoring Serviceという仕組みがあり、デフォルトではオーバヘッド削減のためメトリクス収集は無効となっていますが、モジュールごとに有効化が可能です。JMX Monitoring Serviceでロギングするためには、事前に対象モジュールのモニタリングを有効化させる必要があります。
Monitoring Serviceの設定状況は asadmin get "server.monitoring-service.module-monitoring-levels.*" で一覧が取得できます。
./asadmin get "server.monitoring-service.module-monitoring-levels.*" server.monitoring-service.module-monitoring-levels.cloud=OFF server.monitoring-service.module-monitoring-levels.cloud-elasticity=OFF server.monitoring-service.module-monitoring-levels.cloud-orchestrator=OFF server.monitoring-service.module-monitoring-levels.cloud-tenant-manager=OFF server.monitoring-service.module-monitoring-levels.cloud-virt-assembly-service=OFF server.monitoring-service.module-monitoring-levels.connector-connection-pool=OFF server.monitoring-service.module-monitoring-levels.connector-service=OFF server.monitoring-service.module-monitoring-levels.deployment=OFF server.monitoring-service.module-monitoring-levels.ejb-container=OFF server.monitoring-service.module-monitoring-levels.http-service=HIGH server.monitoring-service.module-monitoring-levels.jdbc-connection-pool=OFF server.monitoring-service.module-monitoring-levels.jersey=OFF server.monitoring-service.module-monitoring-levels.jms-service=OFF server.monitoring-service.module-monitoring-levels.jpa=OFF server.monitoring-service.module-monitoring-levels.jvm=OFF server.monitoring-service.module-monitoring-levels.orb=OFF server.monitoring-service.module-monitoring-levels.security=OFF server.monitoring-service.module-monitoring-levels.thread-pool=HIGH server.monitoring-service.module-monitoring-levels.transaction-service=OFF server.monitoring-service.module-monitoring-levels.web-container=OFF server.monitoring-service.module-monitoring-levels.web-services-container=OFF
今回はHTTPリクエスト処理のスレッドプールを例にするため、http-serviceの監視レベルを変更します。
./asadmin set "server.monitoring-service.module-monitoring-levels.http-service=HIGH"
jconsoleで接続すると、監視が有効化されている場合、amx配下にthread-pool-monが表示されます。xxx-mon配下のMBeanはメトリクスを属性に持っています。
8080ポートで受付中のHTTPリクエストのスレッドプールの現在の利用状況であれば、thread-pool-mon/mon/server-mon[server]/network/http-listener-1/thread-pool/currentthreadbusy.countが現在払い出されているスレッド数を示します。
JMX Monitoring Serviceによるロギングを有効化は、asadmin set-monitoring-configuration --addpropertyをします。
- --addproperty 'name=(attrname) value=(ObjectName)'
- name=は監視したい属性名でcurrentthreadbusyのようなコンポジット型の場合は、.区切りで要素currentthreadsbusy.countを指定すると、該当の要素のみロギングできます。value=はObjectNameで以下のようにjconsoleで監視したいMBeanをクリックすると確認できます。
- --enable true | false
- falseを指定すると、次回起動時よりJMX Monitoring Serviceによるロギングが無効化されます。通常はtrueを指定します。
- --amx true
- Payara(GlassFish)はApplication Server Management Extension (AMX)という仕組みを利用してMBeanを外部に公開しています。AMXの詳細については、AMX: Design and Useに記載されています。jconsoleでamx配下にあるMBeanを対象にロギングしたい場合は --amx true を指定します
- dynamic=true
- オプションで再起動せずにすぐにset-monitoring-configurationした設定によるロギングを開始したい場合に設定します。
./asadmin set-monitoring-configuration --addproperty 'name=currentthreadsbusy.count value=amx:pp=/mon/server-mon[server],type=thread-pool-mon,name=network/http-listener-1/thread-pool' --enabled true --amx true --dynamic=true
設定が有効化されると、$DOMAIN_HOME/logs/server.logには以下のようにログが15秒間隔で出力されます。Filebeatなどで収集してElasticスタックで可視化しておくと、過去の値も振り返ることができます。
[2016-12-23T14:43:50.399+0900] [Payara 4.1] [INFO] [] [fish.payara.jmx.monitoring.MonitoringFormatter] [tid: _ThreadID=47 _ThreadName=payara-monitoring-service(1)] [timeMillis: 1482471830399] [levelValue: 800] [[PAYARA-MONITORING: countcurrentthreadsbusy=0 ]]
まとめ
虚無僧がなくても気軽にJMX MBeanがロギングできるPayaraのJMX Monitoring Serviceを紹介しました。上記以外にもいくつかのオプションがあるため、合わせて公式ドキュメントもご参照ください。
おまけ: MacでPayara起動が遅い、jconsoleで接続できない場合
macOS Sierraでハマったのが、hostnameコマンドで確認できるホスト名localhost.localが/etc/hostsになく、ローカルホストのDNS名が引けない状態だと、Payaraの起動に1分以上かかったり、jconsoleでローカル接続できません。起動中のスレッドダンプを取ると、以下のように名前解決でタイムアウトしているように見えます。
"main" #1 prio=5 os_prio=31 tid=0x00007fd7e1804000 nid=0x1c03 runnable [0x0000700008414000]
java.lang.Thread.State: RUNNABLE
at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928)
at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323)
at java.net.InetAddress.getLocalHost(InetAddress.java:1500)
- locked <0x00000007b8ea7eb8> (a java.lang.Object)
at com.sun.enterprise.util.net.NetUtils.getCanonicalHostName(NetUtils.java:313)
at com.sun.enterprise.universal.glassfish.ASenvPropertyReader$ASenvMap.getHostname(ASenvPropertyReader.java:310)以下のようにlocalhost.localを/etc/hostsに加えると、1分間ほどかかるasadmin start-domainが4秒になりました。
$ sudo vim /etc/hosts 127.0.0.1 localhost localhost.local 255.255.255.255 broadcasthost ::1 localhost localhost.local
Payaraは軽快に起動するサーバです。起動が遅いと思った時は上記に当たっていないか試して見ると効果的です。
