理系学生日記

おまえはいつまで学生気分なのか

logbackの設定を動的に変更する

そういえば昔、Java のアプリでログレベルを動的に変更したいんじゃ、という要望がありました。 当時、結局その要望は諸事情によって受けられなかったんだけど、Logback でそういうの簡単にできる方法があるらしい。主な方法としては、以下の 2 つ。

  • logback.xml を監視する
  • logback の提供する JMX を使用する

logback.xml の定期監視

logback には、logback.xml の修正結果を自動的にリロードしてくれる機能がある。デフォルトでは OFF なんだけど、設定ファイルの root 要素である configurationscan 要素を明示的に true に指定することで有効化される。

<configuration scan="true">
  ...
</configuration>

この設定によって別スレッドが立ち上がり、定期監視が行われる。ソースを見る限り、「変更」の判断は ConfigurationWatchList の以下のメソッドで行われているようで、基本的には lastModified で変更検知される。

    public boolean changeDetected() {
        int len = this.fileWatchList.size();

        for(int i = 0; i < len; ++i) {
            long lastModified = (Long)this.lastModifiedList.get(i);
            File file = (File)this.fileWatchList.get(i);
            if (lastModified != file.lastModified()) {
                return true;
            }
        }

        return false;
    }

アプリケーションが起動しているときにログ設定を変えたいニーズというのは、以下のような場合だと思うけど、変更後の logback.xml で変更前の logback.xml を上書けば良いということになる。

  • 監視不要だけどアラートが発行されちゃうログエントリを一時的に出力しないようにする
  • 異常動作のトラブルシュートのために、特定のクラスのログを出力するようにする

監視間隔はデフォルトで 1 分。それが遅すぎる、というような場合は、さらにl scanPeriod 要素でその間隔を指定する。以下の例は「秒」単位指定だけど、最小粒度だとミリ秒単位で指定できる。 これほどの粒度でのファイル監視が、いったい何のニーズなのかはよくわからん。

<configuration scan="true" scanPeriod="30 seconds" >
  ...
</configuration>

JMX を利用する

logback は、その設定を JMX 経由でも許可している。 実行方法は簡単だけど、Web アプリに載せるときには結構注意しないとメモリリークが発生する。

実行方法は、以下のように jmxConfigurator 要素を設定ファイルに追加するだけ。

<configuration>
  <jmxConfigurator />
  ...
</configuration>

これにより、jconsole でアプリケーションに接続すると、以下のような UI が立ち上がる。 ここでは ROOT ロガーのログレベルを INFO に変更したけど、その変更は確かにアプリケーション側に反映された。

f:id:kiririmode:20180204171834p:plain

WEB アプリに載せるときの注意というのは、WEB/APP サーバから JMXConfigurator への参照が解除されず GC されないことに明示的に対応が必要なことで、このあたりの問題は Logback だけでなく Log4j2 とかにもあるようだった。Logback については、ServletContextListener#contextDestroyed あたりで、

import javax.servlet.ServletContextEvent;
import javax.servlet.ServletContextListener;

import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.LoggerContext;

public class MyContextListener implements ServletContextListener {

  public void contextDestroyed(ServletContextEvent sce) {
    LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    lc.stop();
  }

  public void contextInitialized(ServletContextEvent sce) {
  }
}

とかすれば良い模様。

参考文献

Spring徹底入門

年末年始に Spring 徹底入門をようやく読めた。

Java の FW といえば、Spring を知っておかないともうダメみたいな雰囲気を感じはじめており、以前に買ったままずっと積読してしまっておりました。

Spring は、Spring MVCSpring Batch を 3 年前くらいに使っていたようなのだけれど、当時のエントリを確認するとまだ Spring が 3.1 だった頃のようだった。 今確認すると Spring Framework は既にメジャーバージョンが 5 に到達しており、隔世の感がある。

そういう時代錯誤の状況なのでなんとかせねばならんし、そもそも Spring Boot って何ものじゃい、みたいな老害っぽい状況でもあったので、なんとか時代にキャッチアップしようと思います。

Spring についての感想

Spring については、あんまり大きく変わってないんだなというのが一番の感想でした。当たり前ですが、DI、AOP まわり(Spring Core まわり)は Spring 3 の頃の知識がほぼ使える。Spring Test も大きくは変わっていないように見えました。

一方で、container configuration の方は、当時使っていなかっただけなのか、そもそもそういう機能が無かったのか覚えていないんだけれど、設定を Java で書けるというのは非常に便利なように感じました。 XML で表現できない設定を表現できるというのは良いし、Lint をかけられるし、型の安全性も担保できるし、補完もコードと同様のものが効く。XML は悪くないんだけど、何より書くのに時間がかかるから、Java で設定を記述できる世界感なのはすごく良かった。

FW 自体も疎結合になっているのはすごく柔軟そうで、ViewResolver 等、逐一 Interface が切られているので拡張もずっとやり易そうだと思いました。 Spring Security についても、MVC との統合の方法が分かりやすくて、これだったら導入しても良さそう、という感覚を得るのにすごくよかった。

書籍についての感想

徹底入門シリーズにも個人的には当たり外れはあるんですが、これは当たり。買ってすごく良かったです。

「ここは知っておかないといけないよね」という部分は押さえつつ、ThymeleafMyBatis との統合方法といった Spring という枠に留まらない記載、そして Spring Boot や Spring Security 等の関連プロジェクト等、取り上げる箇所の選定がさすが NTT DATA やなという内容。

Spring に関しては公式のドキュメントが異常に充実していて、基本的にはそこを読めば全貌が把握できるといえばできるんですが、 全体がどのようにできていて、それをどう使っていくのかの概要を俯瞰するためには非常に有用な書籍だったと思います。

あとは公式ドキュメントに目を通していきたいとおもいます。

IntelliJ IDEA ハンズオン

Java については、いままでずっと中途半端にやってきたもので、Eclipse で良いんじゃねということで Eclipse でしか書いてなかった。

(大学の頃は、JDEE を使って Emacs で書いていた(使えという指示だった気がする)けどさすがに苦行だった)

現代の Java の IDE は IntelliJ IDEA を使うのが良いというのは割と共通認識ぽいし、まわりでも IntelliJ を使う人が多い。 このような状況から、ぼくもそろそろ乗り換えないとマズいんだろうなぁと思う節もあり、最近出版されて Twitter でも良くみかけた IntelliJ IDEA ハンズオンの本をこの年始に読んでみました。

内容としては、本当に IntelliJ IDEA という IDE そのものの機能にスコープを当てた内容であって、そういう意味では Eclipse の以下の本と同列にある本だと思います。

総じて、そんなに覚えることは多くないんだという印象。IntelliJ 自体が空気を読んでくれる (Intention Action: いわゆる DWIM) こともあり、それに任せていれば、最初の壁は突破できるんだろうなぁと思いました。

公式サイトやヘルプでいくらでも必要な情報が入手できる中であってもこの手の本が有用なのは、「最初に」必要な情報を分かりやすく説明してくれることにあると思っています *1。 書籍の中にも書いてあるように、IntelliJ は必ずしも初心者向きの IDE ではないので、ぼく自身、実際、最初に DL して使ってみたときはその使い方に戸惑いました。 どこから入っていけば熟達していくのかな、という迷いもあって、なかなか本格的に導入しようとできていなかったので、その意味でも買っただけの価値はあったのかなぁと思っています。

*1:そういう意味では、Maven のドキュメントはなんとかした方が良いと思う

MyFacesでのステートレスビューとCSRF対策の問題(解決済)

JSF において、ポストバックに対する CSRF 対策が実装されているというエントリを書きました。

ここでは、CSRF 対策トークンの値が javax.faces.ViewState という hidden 値に埋め込まれ、それを改竄した場合は ViewExpiredException が発生するという内容を記載しました。

ここで新しい話なのですが、MyFaces を使っているとき、この javax.faces.ViewState の値を stateless という値に変更(改竄) すると、何も例外もでないまま、処理が正常に行えるということがありました。 これは、JSF で導入されたステートレスビューによるものです。ステートレスビューについては、下記のエントリを参照して頂ければと思うのですが、ここでの問題は、

  • 外部から javax.faces.ViewState の値を操作するだけで、サーバ側をステートレスモードで動作させることができてしまう
  • ステートレスモードで動作させた場合は、コンポーネントビューの再構築が行われないので、CSRF 対策としても働かない

ということです。結果として、CSRF 攻撃が一定条件下では成立してしまいます。

すごく気になったので、1 週間ちかく調べていたのですが、どうも MyFaces の問題だったようで、そのものずばりの issue が MyFaces に挙がっていました。結構前に。

コミットは以下。transient="false" の Facelets を、外部から強制的にステートレスビューで動かそうとした場合はエラーとする対応のようです。

というわけで、いま最新版を取ればだいじょうぶなんじゃないかな。

JSFにおけるCSRF対策

CSRF については、一般に正規利用者の意図したリクエストであることを確認することが対策になります。いわゆる徳丸本で紹介されている、具体的な方法としては以下のとおりです。

  • 秘密情報(トークン)の埋め込み
  • パスワード再入力
  • Referer のチェック

JSF には、この CSRF 対策のうち、最初の「トークンの埋め込み」が実装されています。JSF のうちの stateless view を利用していない場合という前提ですが、POST を使用しようとした場合、 javax.faces.ViewState というキー名の hidden フィールドが自動的に埋め込まれ、その値が暗黙のうちに CSRF 対策トークンとして作用します。 逆に GET を使用した場合は、faces-config.xmlprotected-views に対象ページを定義する前提で、同様のトークンがクエリパラメータとして付与されます。

これは、OWASP のいう CSRF 対策の以下のいずれか(たぶん前者)が使われています。

  • Synchronizer (CSRF) Tokens
  • Encrypted Token Pattern

ぼくはもともと、この javax.faces.ViewState は純然たる CSRF 対策なんだろうと思っていたんですが、じつは CSRF は副次的な効果のようです。JSF (2.2) の仕様書には、以下のような記述があり、 javax.faces.ViewState は「現在のビュー(current view) を表現する」ということが記述されています。

When a JavaServer Faces view is rendered, it will contain a hidden field with the identifier javax.faces.ViewState whose value contains the state for the current view.

JavaServer Faces Specification Version 2.2 14.1 Collecting and Encoding View State

この通り、JSF ではビューの状態を保存する際の ID、あるいは、保存したものそのものをこのフィールドに埋め込みます。結果、このフィールドの値が改竄された場合は、ビューを復元できない、という状況が発生し、結果として CSRF 対策になる、というもののようでした。

参考文献

JSFにおけるPostback、そしてライフサイクル

JSF における Postback とは何なのか、っていうのはなかなか本を見てもわかりませんでした。 かといって、こういう概念は実装してもよくわかんなかったりするので、こういうのはやっぱり公式ドキュメントを読んで理解した方が良いだろうと、そこで学んだことを書き留めておきたいと思います。

JSF の仕様書をパッと見たのですが、postback というのはあまり定義されていないようで、もはや前提知識なのかなとも感じました。 そういうわけなので、仕様書からではなく、Oracle の JSF のチュートリアルから引用します。

The request-response lifecycle handles two kinds of requests: initial requests and postbacks. An initial request occurs when a user makes a request for a page for the first time. A postback request occurs when a user submits the form contained on a page that was previously loaded into the browser as a result of executing an initial request.

https://docs.oracle.com/javaee/7/tutorial/jsf-intro006.htm

要するに、JSF におけるリクエストには 2 種類があると。

  • 初期リクエスト (initial request)
  • ポストバックリクエスト (postback request)

要するに、初期リクエストというのがユーザがページに初めてアクセスするときのリクエストで、postback request は、(既にロード済のページから) POST するときのリクエストということかな。

JSF には、リクエストの処理に明確なフェーズがあるのですが、Initial request か Postback Request かによって、個々のフェーズで何をするのか、そして、そもそもどのフェーズを通るのかというのが異なります。 せっかくチュートリアルに記載があるので、そのあたりもまとめてみました。

結論からいえば、initial request は Restore View Phase -> Render Response Phase が実行され、postback request に対しては、基本的に以下の全フェーズが実行されます。

Restore View Phase

このフェーズ自体は、Facelets として記述された View を構築し、Backing Bean 等へのメソッドとの紐付けを行うフェーズになります。

Initial Request に対しては、最初に空の View を構築し、そのまま最終的な Render Response View フェーズに移行します。このフェーズにて、View が構築され、FacesContext にその View が格納されます。ここでいう View っていうのは、たぶん UIViewRoot のことですかね。

一方、Postback Request の場合は、FacesContext の中に既にコンテキストが構築済なので、クライアントあるいはサーバ側(これは設定で切り替えられる)に保存されている状態の情報を通して、それを復元することになります。

Apply Request Values Phase

Postback の場合に行われるフェーズなのですが、ここでは View 中の各コンポーネント、たとえば InputText などが、入力された情報を読み取り、自分自身に保存するというフェーズになります。

Process Validation Phase

このフェーズも Postback で実行されるフェーズですが、各コンポーネントに登録された Validator と Converter を利用して、個々のコンポーネントに入力された値の検証と変換を行います。

Update Model Values Phase

Postback で行われるフェーズですが、ここでは検証済の入力値をコンポーネントツリー中の各コンポーネントに反映します。このフェーズで、Managed Bean にその値が反映されます。

Invoke Application Phase

アプリケーションレベルの処理を実行するフェーズです。ボタンやリンクに設定したイベントが実行されます。

Render Response Phase

View を構築して、そのレンダリングを行うフェーズです。

Initial Request に対しては、リクエストの対象となるページの View を構築して、コンポーネントツリーに登録します。

Postback に対しては、既に View が構築済・コンポーネントツリーにも登録済の状態です。もし、今までのフェーズでエラーがあったのであれば、次画面に留まり、そのエラー内容を表示することになります。

いずれも、コンポーネントツリーから XHTML が生成されます。

WAS Libery ProfileにおけるJVMオプションの設定方法

WAS Liberty Profile において、WAS のランタイムに JVM オプションを指定する方法を探し回っておりました。 この手の JVM オプションは、アプリケーションサーバを立ち上げるスクリプトさえ発見できればすぐなんですけど、今回は Eclipse 上で WebSphere Application Server Developer Tools(WDT) を使って立ち上げるようになっていて、JVM オプションの設定項目もなくてつらみがあった。

結論としては、サーバの基本構成を記述した server.xml と同じ階層にjvm.options ファイルを置いて、JVM オプションを記述すれば良い。 たしかにこういう仕組みだと、WDT に設定項目なくても納得する。

-verbose:gc
-Dconsole.encoding=UTF-8

参考文献

スタックトレースの出力が省略されてると思ったそのときに

よくあったんですよ、手元で例外が発生して原因を辿るためにスタックトレースを辿ってたら、おやおや、「... 3 more」とか出てて、原因が辿れねーぞっていうケース。

 HighLevelException: MidLevelException: LowLevelException
         at Junk.a(Junk.java:13)
         at Junk.main(Junk.java:4)
 Caused by: MidLevelException: LowLevelException
         at Junk.c(Junk.java:23)
         at Junk.b(Junk.java:17)
         at Junk.a(Junk.java:11)
         ... 1 more
 Caused by: LowLevelException
         at Junk.e(Junk.java:30)
         at Junk.d(Junk.java:27)
         at Junk.c(Junk.java:21)
         ... 3 more

... 3 more じゃねーんだオイ、おれはその more を見てぇんだよ、そうしないと原因が分かねーだろが。

もうね、ぼくが悪かった。無知は罪ですごめんなさい。スタックトレースを全出力する JVM のオプションがあるんじゃない???とかしたり顔で言ったりして本当にすみませんでした。反省しております。

文字"..."を含む行が存在することに注目してください。これらの行は、この例外のスタック・トレースの残りが、この例外により引き起こされた例外のスタック・トレースの下からのフレーム数と一致することを示します。通常の(「原因となる例外」をキャッチするのと同じメソッドからラップされた例外がスローされる)場合、この短縮形を使用することで、出力の長さを大幅に短縮できます。上の例は、次のプログラムを実行することで生成されます。

https://docs.oracle.com/javase/jp/8/docs/api/java/lang/Throwable.html#printStackTrace--

ちゃーんと Javadoc に書いてあったんですね。省略は省略でも、「出力が重複してるから省略」してたってこと。Java は偉いよ。ホントえらい。 Java に対して無知すぎる。なんとかしていきたい。

CDIにおけるProducerメソッド

JavaEE 良くわかっていないのですが、それでもプロジェクトが JavaEE 標準だーウオーという状況っぽいので、ちょっと勉強をしはじめております。 ぼくが Java に対して得意意識を持てないのは、こういうところの知識がないのもあるので、そのへんを払拭していこうとがんばらなければ。

今日ははじめて、@Produces というアノテーションを知りました。

@Produces

DI というと、今までずっと「コンテナがオブジェクトを注入する際、どのクラスのオブジェクトを注入するのかはコンテナが決定する」と思ってたんですよね。 開発者は、コンテナに対して型情報といわゆる限定子(非推奨みたいだけど @Named とか、@Qualifier を使って作成したものとか)を教えることで、何を注入してほしいのかを伝えるものだと。

じつはそのあたりには別解があって、コンテナではなく、開発者自身がオブジェクトを生成し、それを注入するようにできる方法があります。 それが Producer メソッドと呼ばれるメソッドをつくる方法で、Producer メソッドの作り方というのが、@Produces アノテーションをメソッドに付与することだと。

Producer メソッドを作ると、DI コンテナが注入対象のフィールドだったり引数だったりを見つけると、その注入対象の型を返却してくれる Producer メソッドを呼んでくれるようになります。

このため、Producer メソッドで注入すべきオブジェクトを生成して、それを返却してやるだけで、動的に注入するオブジェクトのクラスを切り替えたりもできるようになると。なるほど便利だ。

このように、Producer メソッドでは、実行時に注入する型を変える他にも

  • Bean ではないようなオブジェクトを注入する
  • 注入するオブジェクトに対して、コンストラクタでの初期化以外のカスタマイズを実行する

といった特徴を持たせることができます。 百聞は一見にしかずなのですが、Weld 5.0.0.CR1 - CDI Reference Implementation に Producer メソッドで、プリミティブとしての int を生成し注入するための Producer メソッドの実装例がありました。

import javax.enterprise.inject.Produces;


@ApplicationScoped
public class RandomNumberGenerator {


   private java.util.Random random = new java.util.Random(System.currentTimeMillis());

   @Produces @Named @Random int getRandomNumber() {
      return random.nextInt(100);
   }
}

こちらは、Strategy パターンの型を、動的に切り替える例

import javax.enterprise.inject.Produces;

@SessionScoped
public class Preferences implements Serializable {

   private PaymentStrategyType paymentStrategy;

   ...

   @Produces @Preferred
   public PaymentStrategy getPaymentStrategy() {

       switch (paymentStrategy) {
           case CREDIT_CARD: return new CreditCardPaymentStrategy();
           case CHECK: return new CheckPaymentStrategy();
           case PAYPAL: return new PayPalPaymentStrategy();
           default: return null;
       }
   }
}

たいへんに、なるほど〜〜〜感あります。

ただ、これを多用すると、DI における依存性解決がコードから読み取りにくくなるので、まぁ用法用量を守ってお使いくださいという感じなんでしょう。

スレッドダンプを解析する地獄とFastThreadというWebサービス

スレッドダンプというと、JVM 言語に関する運用でマジで困ったときの頼みの綱みたいなイメージある。マジで困ったとき、じゃなくて、カジュアルに見れば良いんだけど、スレッドダンプのフォーマットが異常すぎてつらくなる。

そもそもなんなんだこのゴミみたいなフォーマットは。 一体誰がどういう思想の元でこのフォーマットを決めたのかさっぱり分からないし、人類を苦しめるために未来から来た AI が勝手に策定したのではないか。

"[ThreadPool Manager] - Idle Thread" #42 daemon prio=5 os_prio=31 tid=0x000000012a3a7800 nid=0x15503 in Object.wait() [0x000070000ab66000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:106)
        - locked <0x0000000744b091c0> (a org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor)

   Locked ownable synchronizers:
        - None

"Worker-2" #40 prio=5 os_prio=31 tid=0x000000012a15e800 nid=0x13843 in Object.wait() [0x000070000a8da000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
        - locked <0x0000000741f00888> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:51)

運用してたシステムで Full GC が頻発したりする事象があって、スレッドダンプを目で解析するみたいな地獄みたいなことしたけど、結局原因がネットワークの輻輳にあったとかいう意味のなさだった。 で、そういうのつらすぎるとか思って何年も過ぎたんだけど、今はもう解析してくれる Web サービスとかあった。

単純にスレッドダンプをアップロードするだけで、無料で解析してくれるのが良いかんじ。 スレッドの状態とか、使われてるメソッドとか、CPU 消費してるメソッドとかも解析してダッシュボードに表示してくれる。

f:id:kiririmode:20170625205212p:plain

f:id:kiririmode:20170625205233p:plain

時代は進んでいるし、ゴミみたいなスレッドダンプを目で解析する時代は終わったみたい。そろそろスレッドダンプのフォーマットをマシにしても良いのではなかろうか。

2017/06/29 追記

ご指摘頂いているとおり、Full GC の解析はまずヒープのダンプを取って、どのクラスがどれだけヒープに溜まっているのかを解析するのが定石です。 誤解させてしまったようですみません。

上記の障害事例のときもヒープダンプを取りましたが原因が見えず、スレッドダンプを取っても不明、sar の結果を解析しても不明で、 ネットワークトラフィックと LB の状況からようやく結果が分かったという経緯でした。