javaのlogの時間が巻き戻る現象について

質問

お世話になっております。

現在あるシステムにてjavaを使用しているのですが、
システムが出力するログの時間が巻き戻る現象が発生します。

[1336716021015]
と時間が表示された次のログの時間が
[1336715955765]
というように表示されています。

ソースの內容が開示されていないため、
どのような処理をしているのかは不明なのですが
時間の形式を見るにSystem.currentTimeMillis()
を使用しているのではないかと考えているのですが、
System.currentTimeMillis()を使用した際に
取得する時間が戻る現象は発生するのでしょうか？

また、それ以外でも良いので取得する時間が戻ってしまう原因について
ご教授願えればとおもいます。

回答No.2

中村 拓男（@tknakamuri）

ログ出力側の問題では？

log4j で複数プロセスから同一ファイルへ出力しているとか？

お礼

お騒がせして申し訳ありません。自己解決いたしました。
プログラムの問題ではなく実行するサーバーの問題だったようです。

解答いただきありがとうございました。

回答No.1

pringlez

まず質問をする際には、何のログなのか何のアプリなのか等、もう少し具体的な情報を添えた方がいいと思います。

>System.currentTimeMillis()を使用した際に
>取得する時間が戻る現象は発生するのでしょうか？

あるかないかだけを答えればあるといわざるを得ません。手動でシステム時刻を過去に設定しなおしたときやNTPで時間調整されたときなど。

ただ、システム時刻が戻っていないにもかかわらずSystem.currentTimeMillis()で取得する値が、戻ることがあるかで言えば、ありえないと言い切っていいでしょう。その部分にバグでもあればありえないことは無いですが、そんなところでバグが発生することは考えにくいですし、そもそも私は聞いたことがありません(そのレベルでのバグがあるならば私が聞いたことが無いということはまずありえないと思います)。

そういうことが無いにもかかわらず、そのような現象が発生する原因は、あとは作りの問題だと思います。この場合はおそらく、「System.currentTimeMillis()で値を取得してからログファイルに書き込む」というつくりになっていて、ログファイルに書き込む瞬間までの間に順序の入れ替えが発生している、ただそれだけのことだと思います。

マルチスレッドのシステムであれば、Javaに限らずどんな言語やシステムにもおこりうるありふれた現象かと思います。

お礼

お騒がせして申し訳ありません。自己解決いたしました。
プログラムの問題ではなく実行するサーバーの問題だったようです。

解答いただきありがとうございました。