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.UTF-8 だと 2017/05/28 というフォーマットになっていた。Tomcat 8.5 では、ロケールを何処に切り替えても変化しない。

Tomcat 8.5.5 から、Properties でカスタマイズできるようになった模様。ていうか、それまで日付が 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 で、プロダクト環境が en_US だったりすると、リリース後に面倒が起こったりする。

よって基本ロケールは日本語にし、メッセージだけ英語にするのが無難。

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]

個人的には、C.UTF-8 の方が好み。しかし 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' from DVD 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: Endless CMS GC

メモリが空いているのに 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 も説明されるべき。

まあ、さっさと Java 8 (Metaspace)に移行すればこんな面倒からも解放されるんだけど。

2017-05-01

Animes in the 1st quarter of 2017

アニメは IT エンジニアの必須科目です。

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

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

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

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

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

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

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

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

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

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

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

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

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

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