0
Help us understand the problem. What are the problem?

posted at

【Java】System.out.printlnを複数回呼び出した場合、AtCoderでTLEになってしまうので実際に実行時間を計測してみた

 AtCoderにて、System.out.printlnを複数回呼び出すと、AtCoder228_CAtCoder231_Cのように最悪$10^5$行くらいの文字列を出力する場合、TLEになる場合がありました。
 標準出力の複数回呼び出しによるオーバーヘッドの時間がかかりTLEになったものだと思います。本記事では同じ長さの文字列について、System.out.printlnを複数回呼び出して標準出力した場合の時間と、一度に標準出力した場合の時間を実際に比較しようと思います。
 計測するコードの実装内容は$0~10^5$をインクリメントした文字列を改行して出力する処理です。この処理を100回繰り返して各実行毎の実行時間を取得します。$10^5$にした理由はAtCoderで出力する行数として、よく見かけるからです。
 計測する手法は以下の三パターンです。

  • 手法-1 System.out.printlnの複数回呼び出して出力する。
  • 手法-2 StringBuilderにより文字を連結させてから一度に出力する。
  • 手法-3 PrintWriterオブジェクトを利用し、フラッシュ(標準出力)されるのを1回にする。

手法-1 System.out.printlnの複数回呼び出し

 単純にSystem.out.printlnを複数回呼び出します。計測に利用するコードは以下のものです。

System.out.printlnの複数回呼び出しのサンプルコード
public class PrintTest1 {

	public static void main(String[] args) throws IOException {

		// 出力する時刻を格納するリスト
		List<String> results = new ArrayList<String>();
		System.out.println("計算開始");
		for (int i = 0; i < 100; i++) {
			// 開始時刻の取得(ミリ秒)
			long startTime = System.currentTimeMillis();
			// 計算
			caliculate();
			// 計算時刻の格納
			results.add(String.valueOf(System.currentTimeMillis() - startTime));

			try {
				//1秒待機する
				Thread.sleep(1000);
			} catch (InterruptedException e) {
			}
		}

		// 結果の出力
		Files.write(Paths.get("output1.log"), results);
		System.out.println("計算終了");

	}

	/**
	 * System.out.printlnを用いて0~10^5の数字を標準出力する
	 */
	public static void caliculate() {
		for (int i = 0; i <= 100000; i++) {
			System.out.println(i);
		}
	}
}

手法-2 StringBuilderによる文字連結

 StringBuilderによって文字を連結させた後、一度にSystem.out.printlnで出力します。計測に利用するコードは以下のものです。

StringBuilderによる文字連結した場合のサンプルコード
import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.util.ArrayList;
import java.util.List;

public class PrintTest2 {

	public static void main(String[] args) throws IOException {

		// 出力する時刻を格納するリスト
		List<String> results = new ArrayList<String>();
		System.out.println("計算開始");
		for (int i = 0; i < 100; i++) {
			// 開始時刻の取得(ミリ秒)
			long startTime = System.currentTimeMillis();
			// 計算
			caliculate();
			// 計算時刻の格納
			results.add(String.valueOf(System.currentTimeMillis() - startTime));

			try {
				//1秒待機する
				Thread.sleep(1000);
			} catch (InterruptedException e) {
			}
		}

		// 結果の出力
		Files.write(Paths.get("output2.log"), results);
		System.out.println("計算終了");

	}

	/**
	 * StringBuilderを用いて0~10^5の数字を標準出力する
	 */
	public static void caliculate() {
		StringBuilder sb = new StringBuilder();
		for (int i = 0; i <= 100000; i++) {
			sb.append(i).append('\r').append('\n');
		}
		System.out.print(sb.toString());
	}

}

手法-3 PrintWriterを利用する

 PrintWriterオブジェクトを利用して、flushメソッドによりフラッシュ(標準出力)されるタイミングを調整する。計測に利用するコードは以下のものです。

PrintWriterを利用した場合のサンプルコード
import java.io.IOException;
import java.io.PrintWriter;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.util.ArrayList;
import java.util.List;

public class PrintTest3 {

	public static void main(String[] args) throws IOException {

		// 出力する時刻を格納するリスト
		List<String> results = new ArrayList<String>();
		System.out.println("計算開始");
		for (int i = 0; i < 100; i++) {
			// 開始時刻の取得(ミリ秒)
			long startTime = System.currentTimeMillis();
			// 計算
			caliculate();
			// 計算時刻の格納
			results.add(String.valueOf(System.currentTimeMillis() - startTime));

			try {
				//1秒待機する
				Thread.sleep(1000);
			} catch (InterruptedException e) {
			}
		}

		// 結果の出力
		Files.write(Paths.get("output3.log"), results);
		System.out.println("計算終了");

	}

	/**
	 * PrintWriterとflushメソッドを用いて0~10^5の数字を標準出力する
	 */
	public static void caliculate() {
		PrintWriter pw = new PrintWriter(System.out);
		for (int i = 0; i <= 100000; i++) {
			pw.println(i);
		}
		pw.flush();
	}
}

計測結果と考察

 open-jdk-11.0.2で実行しました。実行結果の分布の箱ひげ図は以下のものになりました。
image.png
 また、実行結果の平均値・中央値・最大値・最小値・95%の信頼区間と99%の信頼区間は以下のものです。

(単位:ミリ秒) 手法1-System.out.println複数 手法2-StringBuilder 手法3-PrintWriter
平均値 563.51 208 246.13
中央値 573.5 192 250.5
最大値 864 354 374
最小値 448 94 135
標準偏差 62.4157606 75.35840291 61.73168644
95%信頼区間 12.38464102 14.95274205 12.24890587
95%信頼区間の最大値 575.894641 222.952742 258.3789059
95%信頼区間の最小値 551.125359 193.047258 233.8810941
99%信頼区間 16.39290943 19.79217207 16.21324382
99%信頼区間の最大値 579.9029094 227.7921721 262.3432438
99%信頼区間の最小値 547.1170906 188.2078279 229.9167562

 計測した環境ではSystem.out.printlnを複数呼び出した場合、他の手法と比較して約2倍以上かかってしまいました。最大でも800ミリ秒かかってしまうのでAtCoderの実行時間制限が2secの場合、致命傷になってしまいそうですね。System.out.printlnを複数回呼び出すのは避けた方がいいでしょう。

付録

実際に計測した生データが以下のものです。

手法1-System.out.println複数 手法2-StringBuilder 手法3-PrintWriter
572 141 154
595 99 141
558 94 135
567 100 144
589 99 143
603 102 152
583 109 164
578 108 169
550 114 152
552 110 172
586 128 140
597 120 143
566 117 165
864 118 162
583 119 163
594 122 160
480 124 178
487 124 169
463 128 174
487 132 175
472 135 174
503 140 191
475 133 192
480 147 197
713 138 197
477 143 206
474 147 191
505 146 194
448 160 201
488 150 213
471 155 202
539 342 205
561 160 205
613 156 216
584 154 215
592 166 208
590 167 228
507 164 218
668 160 232
620 164 235
598 171 227
593 168 240
641 170 234
649 179 229
610 180 242
606 182 257
631 186 249
642 180 248
626 180 236
605 190 251
566 186 244
467 194 270
466 195 270
478 194 258
493 198 269
573 205 250
588 204 258
583 197 260
576 197 269
572 258 290
512 206 273
543 282 265
545 244 269
563 248 274
584 257 272
586 271 277
583 288 282
580 284 292
597 270 299
605 275 278
556 294 290
582 280 291
597 280 290
545 290 281
574 291 295
629 293 292
604 291 313
620 298 295
504 234 299
455 234 300
485 241 316
549 238 313
504 248 324
591 242 307
627 308 313
539 247 314
558 284 307
524 304 316
547 301 348
621 328 334
593 317 335
596 321 315
539 325 321
604 336 325
548 315 319
606 325 343
547 326 374
616 339 338
518 354 348
478 342 350

Register as a new user and use Qiita more conveniently

  1. You can follow users and tags
  2. you can stock useful information
  3. You can make editorial suggestions for articles
What you can do with signing up
0
Help us understand the problem. What are the problem?