システムを慎むout.println()のパフォーマンステスト
3738 ワード
一.の原因となる
この2,3日問題を検証したところ、突然問題が発見された.out.println()はテストの正確性に影響します.
システムのせいでout.println()はもともと性能が悪い!!!
だからわざわざ個性テストをしました.
二.テストコード
テストコードは簡単です.2つのコードの間にシステムを1行追加しました.out.println(). その後、性能への影響をテストする.package com.system;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import java.util.ArrayList;
import java.util.LinkedList;
import java.util.concurrent.TimeUnit;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import org.openjdk.jmh.runner.options.Options;
import java.util.*;
import java.util.concurrent.TimeUnit;
@BenchmarkMode(Mode.AverageTime) //
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@Warmup(iterations = 2, time = 1, timeUnit = TimeUnit.SECONDS) // 2 , 1s
@Measurement(iterations = 5, time = 1, timeUnit = TimeUnit.SECONDS) // 5 , 1s
@Fork(2) // fork 2
@State(Scope.Thread) //
public class SystemTest {
public static void main(String[] args) throws RunnerException {
//
Options opt = new OptionsBuilder()
.include(SystemTest.class.getSimpleName()) //
// .output("/a/jmh-map.log") //
.build();
new Runner(opt).run(); //
}
@Benchmark
public void nullFor() {
for (int i = 0 ; i < 100 ; i++){
String x = String.valueOf(i) ;
}
}
@Benchmark
public void OutFor() {
for (int i = 0 ; i < 100 ; i++){
System.out.println(i);
}
}
}
テスト結果:Benchmark Mode Cnt Score Error Units
SystemTest.OutFor avgt 10 1894854.560 ± 1519929.208 ns/op
SystemTest.nullFor avgt 10 1692.085 ± 200.099 ns/op
三.ソース分析
synchronizedキーワードが大量に使われているので、これは同期して実行されます.
大量の同時または使用がある場合、synchronizedはロックのアップグレードをもたらす.ロックがヘビー級ロックに膨張すると、システム性能への影響は災難的!!! /**
* Prints an integer and then terminate the line. This method behaves as
* though it invokes {@link #print(int)}
and then
* {@link #println()}
.
*
* @param x The int
to be printed.
*/
public void println(int x) {
synchronized (this) {
print(x);
newLine();
}
}
private void write(String s) {
try {
synchronized (this) {
ensureOpen();
textOut.write(s);
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush && (s.indexOf('
') >= 0))
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}
private void newLine() {
try {
synchronized (this) {
ensureOpen();
textOut.newLine();
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush)
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}
テストコードは簡単です.2つのコードの間にシステムを1行追加しました.out.println(). その後、性能への影響をテストする.
package com.system;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import java.util.ArrayList;
import java.util.LinkedList;
import java.util.concurrent.TimeUnit;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import org.openjdk.jmh.runner.options.Options;
import java.util.*;
import java.util.concurrent.TimeUnit;
@BenchmarkMode(Mode.AverageTime) //
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@Warmup(iterations = 2, time = 1, timeUnit = TimeUnit.SECONDS) // 2 , 1s
@Measurement(iterations = 5, time = 1, timeUnit = TimeUnit.SECONDS) // 5 , 1s
@Fork(2) // fork 2
@State(Scope.Thread) //
public class SystemTest {
public static void main(String[] args) throws RunnerException {
//
Options opt = new OptionsBuilder()
.include(SystemTest.class.getSimpleName()) //
// .output("/a/jmh-map.log") //
.build();
new Runner(opt).run(); //
}
@Benchmark
public void nullFor() {
for (int i = 0 ; i < 100 ; i++){
String x = String.valueOf(i) ;
}
}
@Benchmark
public void OutFor() {
for (int i = 0 ; i < 100 ; i++){
System.out.println(i);
}
}
}
テスト結果:
Benchmark Mode Cnt Score Error Units
SystemTest.OutFor avgt 10 1894854.560 ± 1519929.208 ns/op
SystemTest.nullFor avgt 10 1692.085 ± 200.099 ns/op
三.ソース分析
synchronizedキーワードが大量に使われているので、これは同期して実行されます.
大量の同時または使用がある場合、synchronizedはロックのアップグレードをもたらす.ロックがヘビー級ロックに膨張すると、システム性能への影響は災難的!!! /**
* Prints an integer and then terminate the line. This method behaves as
* though it invokes {@link #print(int)}
and then
* {@link #println()}
.
*
* @param x The int
to be printed.
*/
public void println(int x) {
synchronized (this) {
print(x);
newLine();
}
}
private void write(String s) {
try {
synchronized (this) {
ensureOpen();
textOut.write(s);
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush && (s.indexOf('
') >= 0))
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}
private void newLine() {
try {
synchronized (this) {
ensureOpen();
textOut.newLine();
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush)
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}
/**
* Prints an integer and then terminate the line. This method behaves as
* though it invokes {@link #print(int)}
and then
* {@link #println()}
.
*
* @param x The int
to be printed.
*/
public void println(int x) {
synchronized (this) {
print(x);
newLine();
}
}
private void write(String s) {
try {
synchronized (this) {
ensureOpen();
textOut.write(s);
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush && (s.indexOf('
') >= 0))
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}
private void newLine() {
try {
synchronized (this) {
ensureOpen();
textOut.newLine();
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush)
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}