2017-05-28

Tomcat 8.5: Timestamp format in logs

8 年ぶりに最新の Tomcat を追いかけたら、ログのタイムスタンプが ks になっていた。

logs/catalina.2017-05-28.log:

28-May-2017 16:06:38.023 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.15
28-May-2017 16:06:38.023 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          May 5 2017 11:03:04 UTC
28-May-2017 16:06:38.024 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.15.0
28-May-2017 16:06:38.024 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
28-May-2017 16:06:38.024 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            2.6.32-573.el6.i686
28-May-2017 16:06:38.024 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          i386

Tomcat 6 では、日付フォーマットはロケールによって変わり、ja_JP だと 2017/05/28 というフォーマットになっていた。Tomcat 8.5 では、ロケールを何処に切り替えても変化しない。

Tomcat 8.5.5 から、フォーマットをカスタマイズできるようになった模様。ていうか、それまで日付が dd-MMM-yyyy に決め打ちって、流石に乱暴すぎやしないか。よくみんな我慢できたな。そして変更後について、これだとタイムスタンプを出したくない場合に対応できてない(小数部分だけ出る)んだけど。ほんともう、分かってないなあ。

ともかく、今回は logging.properties に設定を入れれば解決する。

conf/logging.properties:

org.apache.juli.OneLineFormatter.timeFormat = yyyy-MM-dd HH:mm:ss

logs/catalina.2017-05-28.log:

2017-05-28 16:09:42.349 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.15
2017-05-28 16:09:42.355 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          May 5 2017 11:03:04 UTC
2017-05-28 16:09:42.355 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.15.0
2017-05-28 16:09:42.355 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
2017-05-28 16:09:42.355 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            2.6.32-573.el6.i686
2017-05-28 16:09:42.356 情報 [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          i386
2017-05-28 16:09:42.356 情報 [main] org.apache.catalina.startup.VersionLoggerLis
<...snip...>
2017-05-28 16:09:42.642 情報 [main] org.apache.catalina.core.StandardService.startInternal サービス [Catalina] を起動します

タイムスタンプはこれで良いとして、もう 1 つやっておきたいことがある。上記では、Tomcat が出すメッセージは日本語になっているが、トラブルシュート時に逆に不便なので、これは英語にしておきたい。最も簡単には、LANG=en_US.UTF-8 などとする方法があるが、これはかなり影響が大きいのでお勧めしない。

例えば locale コマンドを叩いてみると、

# LANG=en_US.UTF-8 locale
LANG=en_US.UTF-8
LC_CTYPE="en_US.UTF-8"
LC_NUMERIC="en_US.UTF-8"
LC_TIME="en_US.UTF-8"
LC_COLLATE="en_US.UTF-8"
LC_MONETARY="en_US.UTF-8"
LC_MESSAGES="en_US.UTF-8"
LC_PAPER="en_US.UTF-8"
LC_NAME="en_US.UTF-8"
LC_ADDRESS="en_US.UTF-8"
LC_TELEPHONE="en_US.UTF-8"
LC_MEASUREMENT="en_US.UTF-8"
LC_IDENTIFICATION="en_US.UTF-8"
LC_ALL=

ロケールが関与するものは結構ある。日本人的には、LC_TIME (日時フォーマット)や LC_COLLATE (文字列ソート順)あたりでトラブるのがロケールあるある。開発者の環境が ja_JP で、プロダクト環境がそれ以外だったりすると、リリース後に面倒が起こったりする。

よって基本ロケールは日本語とし、メッセージだけ英語にするのが無難。理想的には、ロケールは開発環境(もしくはアプリケーション仕様)の一部として管理されるべきだとは思う。

export LANG=ja_JP.UTF-8
export LC_MESSAGES=en_US.UTF-8

logs/catalina.2017-05-28.log:

2017-05-28 16:11:40.304 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.15
2017-05-28 16:11:40.308 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          May 5 2017 11:03:04 UTC
2017-05-28 16:11:40.308 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.15.0
2017-05-28 16:11:40.308 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
2017-05-28 16:11:40.309 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            2.6.32-573.el6.i686
2017-05-28 16:11:40.309 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          i386
<...snip...>
2017-05-28 16:11:40.527 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]

個人的には、en_US より C の方が好み。しかし RHEL 系は RHEL7 であっても C.UTF-8 が入ってないので、en_US で我慢しておく。

2017-05-13

Excel: Open TBX file

よくドキュメントを書く人にとって、「カタカナ表記をどうするか?」というのは常に悩ましい問題だ。つまり、「サーバ」or「サーバー」?、「インタフェース」or「インターフェイス」?とかいうやつ。私は、以前は JTCA とかいう所の「外来語(カタカナ)表記ガイドライン」に従っていた。

しかしこれ、実際に使ってみると色々と美味くない。まず、

  • IT 用語の例が少ない。

一応、用語集は付いているものの、一般用語が大半を占めるため、IT 業界に居てこれで事足りることは絶対にない。更に、

  • Microsoft 用語と相違がある。

例えば、上記ガイドラインはで「レジストリー」、Windows はで「レジストリ」。画面キャプチャして手順書を作ったりすると、この不一致が気持ち悪くて仕方ない。Windows ユーザーが最も多いことは周知の事実なのだから、合わせるならむしろ Windows に合わせるべきだろう。

ということで、今では全て Microsoft 用語を使うようにしている。

ここでは用語検索もできるし、当然ながら IT 用語は網羅されている。ここで検索できない用語を使うということは、何か間違っている可能性すらある。

さて、上記の用語検索は便利だが、お世辞にも使い易いとは言えない。それどころか偶にエラーになったり、サイトにアクセスできない時すらある。なので、用語集をローカルにダウンロードして参照したい、となるのは当然の流れ。実際、ダウンロードは簡単にできる。しかしその拡張子は .tbx とかなってる。

一体これをどうしろと・・・? :-o

tbx でググってみても、要領を得ないサイトばかり。危うく得体の知れないソフトウェアをインストールさせられそうになったりする。そうじゃなくて、もっとこう、何かないの?

just add ".xml" to your file, open in Excel ...

なになに? 「拡張子を .xml にして Excel で開け」と。ふむ、何かダイアログが出てきたけど適当に OK して・・・、お、何か Excel がすごい頑張ってるっぽい(タスクマネージャーを見ながら)。そして待つこと数分。

Excel 先輩まじイケメン。 X-D

あとは不要な列を削除して .xlsx 形式で保存すれば、サイズもぐっとコンパクトになる。いやー、久しぶりに Excel 先輩の本気を見た。

2017-05-07

RHEL: `yum' using DVD media on the fly

OS メディアをリポジトリにして yum を使いたい。インターネットに繋がらない環境では、良くある話。CentOS では、最初からそういう設定ファイルが用意されている。

CentOS 6.2: /etc/yum.repos.d/CentOS-Media.repo:

# CentOS-Media.repo
#
# This repo is used to mount the default locations for a CDROM / DVD on
#  CentOS-6.  You can use this repo and yum to install items directly off the
#  DVD ISO that we release.
#
# To use this repo, put in your DVD and use it with the other repos too:
#  yum --enablerepo=c6-media [command]
#
# or for ONLY the media repo, do this:
#
#  yum --disablerepo=\* --enablerepo=c6-media [command]

[c6-media]
name=CentOS-$releasever - Media
baseurl=file:///media/CentOS/
        file:///media/cdrom/
        file:///media/cdrecorder/
gpgcheck=1
enabled=0
gpgkey=file:///etc/pki/rpm-gpg/RPM-GPG-KEY-CentOS-6

なので、次のようなコマンドでいける。

# mkdir -p /media/CentOS

# mount -r /dev/cdrom /media/CentOS

# yum --disablerepo='*' --enablerepo=c6-media install <package>...

# eject /media/CentOS

しかし、RHEL にはそんな気の利いた設定ファイルはない。よって、CentOS 同様の設定ファイルを作る必要がある。

と、以上はググれば直ぐに出てくる話。我が侭な私としては、できれば設定ファイルを作らずにやりたい。幸い OS メディアには、media.repo という設定ファイルが存在する。

RHEL6.8: media.repo:

[InstallMedia]
name=Red Hat Enterprise Linux 6.8
mediaid=1460645249.825876
metadata_expire=-1
gpgcheck=0
cost=500

これを使えば、設定ファイルを作らずに下記のようにできる。

# mount -r /dev/cdrom /media

# yum -c /media/media.repo --setopt InstallMedia.baseurl=file:///media install <package>...

# eject /media

ただし、--setopt は RHEL6 以降の yum でしか使えない。RHEL5 以前の場合は、やはり何かしらの設定ファイルを作る必要がある。

2017-05-03

Java: CMS GC is endless

メモリが空いているのに CMS GC が掛かり続けることがある。といっても Full GC ではないので、CPU と GC ログを食うだけで運用上の問題はないのだが、はっきりした理由が分からないと安全だと言い切ることもできない。私もこれまでに何度か調べてきたが、ずっと原因が分からずにいた。

今は少しググれば有用な情報がたくさん得られる。いい時代になったもんだ。これらの情報が 2010 年以前にあれば、私もどれだけ楽ができたか知れない。しかし、これらの情報は今回の私の問題を解決しない。例えば nekop 氏によると、

CMSが開始されるトリガーは二つある。ひとつはOld領域の利用率がCMSInitiatingOccupancyFractionに到達した場合。もうひとつは今CMS走らせないと先にヒープ埋まっちゃうよね、という統計判断を元にしたトリガー。

CMSInitiatingOccupancyFraction の初期値は 92%。しかし繰り返すが、メモリは十分に空いている。ヒープを 50% しか使用していないのに、CMS GC が掛かり続けることの説明にはならない。じゃあもう 1 つの「統計判断」とは何なのか。

後者の統計については細かい話になるので省略する。知りたい人はソース嫁。

orz。うん、まあ、ね。私もかれこれ 5 年以上この現象を見てきているので、そろそろ億劫がらずにコードを読んでみる時期なのかも知れないな。

現場で動いているのは Java 6 なのだが、ソースコードを見つけられなかったので Java 7 を見てみる。しかしコードを見たからって、そんな簡単に解決するんだったら世話ないっての。

・・・1 時間後。

解決しちゃった。 :-D

bool CMSCollector::shouldConcurrentCollect() {

  // ...snip...

  // Otherwise, we start a collection cycle if either the perm gen or
  // old gen want a collection cycle started. Each may use
  // an appropriate criterion for making this decision.
  // XXX We need to make sure that the gen expansion
  // criterion dovetails well with this. XXX NEED TO FIX THIS
  if (_cmsGen->should_concurrent_collect()) {
    if (Verbose && PrintGCDetails) {
      gclog_or_tty->print_cr("CMS old gen initiated");
    }
    return true;
  }

  // ...snip...

  if (CMSClassUnloadingEnabled && _permGen->should_concurrent_collect()) {
    bool res = update_should_unload_classes();
    if (res) {
      if (Verbose && PrintGCDetails) {
        gclog_or_tty->print_cr("CMS perm gen initiated");
      }
      return true;
    }
  }
  return false;
}

重要なのは後半の部分。つまり、通常のヒープ領域だけでなく、Permanent 領域も CMS のトリガーになる ということ。この閾値は CMSInitiatingPermOccupancyFraction で、やはり初期値は 92%。

これで全てに納得がいった。これはつまり、Permanent 領域の使用量を把握して MaxPermSize を最適化しているほど、この現象に遭いやすくなるということだ。そういう場合、この値は限りなく 100% に近づけるのが正しい。(でなければ MaxPermSize を増やす)

-XX:CMSInitiatingPermOccupancyFraction=99

CMS でも、どうせ偶に concurrent mode failure や promotion failed 由来の Full GC は起こる(このとき Permanent 領域も GC される)し、Permanent 領域の変動がよほど大きいアプリケーションでもなければ、これで良いと思う。

しかしこの Permanent 領域の CMS トリガーは、もっと有名になって良いと思う。少なくとも、CMSInitiatingOccupancyFraction を出す際は、合わせて CMSInitiatingPermOccupancyFraction についても触れるべき。

2017-05-01

Animes in the 1st quarter of 2017

アニメは IT エンジニアの必須科目です。 ということで簡単なレビューを。

まさか 1 年も続くとは思わなかったよ。必殺技の演出とか、紅緒たんが可愛いとか、良い面は沢山あれど、やっぱり 1 年は間延びする。2 クールくらいでギュッと圧縮して欲しかった。

最初はイマイチだったが、コーチが出てきてから良くなった。でもまだ足りない。もっと勝負に対する真摯な姿勢を描写して欲しい。「勝敗は試合の前に決まっている」というのは、何事にも通じる良い言葉。

前期より視聴。本当に True End 版が来たっぽいが、話は訳の分からない方向に。これは Bad End 版の方が面白いですわ。女子キャラが魅力的な作品で女子キャラをろくに出さないとか、ちょっと分からないですね。

ヴィーネ良し、サターニャはなお良し。ラフィもまあ許せる。たがガヴ、てめーは駄目だ。作品のヒロインが作品を一番面白くなくしている。正直、中の人が合ってないように思う。逆に、サターニャの大空直美は覚えた。

前期に続き、作品は面白いと思う。しかし、OP からして、作画はどうしてこうなった。こうなる前に誰か止められなかったのか。これは間違いなくスタジオディーンの汚点となった。

この制作会社はいつも初話で芸術レベルの絵を見せてくれるが、いつもそれが続かないのは何故なのか。今回は話も単調でつまらない。結局、何ひとつ謎が解明されてないような。

知らずに見たら京アニだったが、なぜこれをアニメ化しようと思ったのだろう。まあ、カンナたんが可愛かったので見た甲斐はあった。あとエンジニア的には、Python のソースコードとか。

ヒロインが「残虐姫」という割には、案外チョロくてテンプレートだったのはアレだが、何だかんだ可愛かったので良し。次回に続くのは構わないが、もう少し切りの良いところで区切ろうよ。

前作は未視聴。絵はちょっとアレだが、そこは科学アドベンチャーシリーズ、話は普通に面白い。これなら面倒くさがらずに前作も見ておけば良かった。

実は 0.5 話で切ったのだが、どうしてこうなった。見返してみても理由が分からない。当事者も「正直なにが起きているのか困惑」したらしいが、ほんこれ。納得はいかないがこうなった以上、必須科目であるのは間違いない。

かつて上京していた身としては、アキバの現状が垣間見れたのは興味深い。東京に住んでいたらより楽しめたと思う。まあ作品が面白いかは別として。

OP を見れば話が読めて、そこから意外性もないので、見ていて退屈。それより巻末の「ちぇいん黒にくる!!」が本命だった。あのキャラを大塚明夫が演じていることだけでも価値がある。

見る前は全く期待していなかったが、人情味あふれた心地よい勧善懲悪もの。結局、今期はこれが一番面白かった。ぜひ続きを作って欲しい。

ノイタミナ枠でこの手の作品をやるとは意外。原作者の漫画は好きな方で、本作は先っぽしか読んでなかったので普通に楽しめた。ただ、題名にそぐわない綺麗な終わり方が少し物足りない。