はじめに

前回、Javaでファイルにログ出力という記事を書いた。そこでログ出力メソッドをsyncronizedメソッドにすることでログファイルに対して排他制御できそうだと書いたので、今回はそれを検証してみたい。

検証方法

ログ出力メソッドを10000回呼び出すスレッドを10個並列に実行し、各スレッドで指示したログがもれなくログファイルに出力されているかを確認する。

検証ソース

スレッドについては、いろんなサンプルがあるから、特に解説は不要だろう。
ログ出力メソッドはいろんなスレッドから呼び出せるように、LogWriterクラスのwriteLogメソッドに移動した。

LogWriterTest.java

import java.io.File;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.Calendar;
import java.io.*;

public class LogWriterTest{

    public static void main(String[] argv){

        ThreadSample[] threadSamples = new ThreadSample[10];

        // スレッドの準備
        for (int i = 0; i < threadSamples.length; i++) {
            threadSamples[i] = new ThreadSample("Trhead["  + i + "]");
        }

        // スレッドの開始
        for (int i = 0; i < threadSamples.length; i++) {
            threadSamples[i].start();
        }

    }
}

// ログ出力クラス
class LogWriter {
    public static SimpleDateFormat sdf = new SimpleDateFormat("YYYY/MM/dd HH:mm:ss");


    // ログ出力メソッド
    public static synchronized void writeLog(String text) {
        Calendar calendar = Calendar.getInstance();

        String OUTPUT_DIR = "out";

        int year = calendar.get(Calendar.YEAR);
        int month = calendar.get(Calendar.MONTH) + 1;
        Date date = calendar.getTime();

        String yearStr = String.format("%04d", year);
        String monthStr = String.format("%02d", month);

        //　ログ出力
        String file_name = OUTPUT_DIR + File.separator + yearStr + "_" + monthStr + ".log";
        File file = new File(file_name);
        FileWriter fw = null;
        String line = sdf.format(date) + "," + text;
        try {
            fw = new FileWriter(file, true);
            fw.write(line + "\n");
        } catch (IOException e) {
            e.printStackTrace();
        } finally {
            if (fw != null) {
                try {
                    fw.close();
                } catch (Exception e2) {
                    e2.printStackTrace();
                }
            }
        }
    }
}

class ThreadSample extends Thread {

    // スレッド名
    private String name = null;

    public ThreadSample(String name) {
        this.name = name;
    }

    // ログに10000行書き込むスレッド
    public void run() {
        for (int i = 0; i < 10000; i++) {
            System.out.println(name + "," + i);
            LogWriter.writeLog(name + "," + i + ":hogehoge");
        }
    }
}

検証結果

ファイルの中身

ファイルの中身はこんな感じで壊れてはなさそう。あといろんなスレッドのログが並列でファイルに出力されている様子もうかがえる。

2020/05/23 09:48:59,Trhead[2],0:hogehoge
2020/05/23 09:48:59,Trhead[5],0:hogehoge
2020/05/23 09:48:59,Trhead[6],0:hogehoge
2020/05/23 09:48:59,Trhead[9],0:hogehoge
2020/05/23 09:48:59,Trhead[0],0:hogehoge
2020/05/23 09:48:59,Trhead[7],0:hogehoge
2020/05/23 09:48:59,Trhead[8],0:hogehoge
2020/05/23 09:48:59,Trhead[3],0:hogehoge
2020/05/23 09:48:59,Trhead[1],0:hogehoge
2020/05/23 09:48:59,Trhead[4],0:hogehoge
2020/05/23 09:48:59,Trhead[1],1:hogehoge
2020/05/23 09:48:59,Trhead[3],1:hogehoge
2020/05/23 09:48:59,Trhead[8],1:hogehoge
2020/05/23 09:48:59,Trhead[7],1:hogehoge
2020/05/23 09:48:59,Trhead[0],1:hogehoge
2020/05/23 09:48:59,Trhead[9],1:hogehoge
2020/05/23 09:48:59,Trhead[6],1:hogehoge
2020/05/23 09:48:59,Trhead[5],1:hogehoge
2020/05/23 09:48:59,Trhead[2],1:hogehoge
2020/05/23 09:48:59,Trhead[5],2:hogehoge
2020/05/23 09:48:59,Trhead[6],2:hogehoge

件数

件数も、各スレッドの10000件、合計100000件となっており、もれなく出力されていることが確認できた。

$ grep 'Trhead\[0\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[1\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[2\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[3\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[4\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[5\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[6\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[7\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[8\]' 2020_05.log |wc -l
10000

$ grep 'Trhead\[9\]' 2020_05.log |wc -l
10000

$ wc -l 2020_05.log
100000 2020_05.log

おわりに

このメソッドを使ってガンガンログ出力するぞ！

追記1

ちなみに、syncronizedをつけなくても、小職の環境ではもれなくログ出力された。処理も圧倒的に高速だった。
ただ、偶然ということもありえるので、処理時間を犠牲にしてもsyncronizedはつけた方がよいだろう。

追記2

小職のプログラムでは、synchronizedメソッドの中で日付の処理やファイル名の決定を行っているが、これを呼び出し側に移動し、同期処理の時間を短くすれば、多少速くなるかもしれない(未実験)。

Javaで複数のスレッドからsynchronizedメソッドを呼び出してみる