最新消息:雨落星辰是一个专注网站SEO优化、网站SEO诊断、搜索引擎研究、网络营销推广、网站策划运营及站长类的自媒体原创博客

Why is the performance of System.err is significantly lower than System.out in Java? - Stack Overflow

programmeradmin5浏览0评论

I'm conducting a load test on System.out, System.err and logger.info(using SLF4J + Logback) in a Java 8 environment with Spring Boot 2.6.0 and Logback 1.2.7. I have packaged my project into an executable JAR and run it on Windows 11 using the following command: java -jar -Xms256m -Xmx256m .\happyTest-1.0.2-SNAPSHOT.jar > .\logs\happyTest2.log 2>&1 .
Here is API code:

@RestController
@RequestMapping("/log")
public class LogController {

    private static final Logger logger = .slf4j.LoggerFactory.getLogger(LogController.class);

    private static final int LOOP_COUNT = 100;

    @GetMapping("/system-out")
    public String logSystemOut() {
        long startTime = System.currentTimeMillis();
        for (int i = 0; i < LOOP_COUNT; i++) {
            System.out.println("hello world");
        }
        long endTime = System.currentTimeMillis();
        return "Logged messages in " + (endTime - startTime) + " ms";
    }

    @GetMapping("/system-err")
    public String logSystemErr() {
        long startTime = System.currentTimeMillis();
        for (int i = 0; i < LOOP_COUNT; i++) {
            System.err.println("hello world");
        }
        long endTime = System.currentTimeMillis();
        return "Logged messages in " + (endTime - startTime) + " ms";
    }

    @GetMapping("/info")
    public String logInfo() {
        long startTime = System.currentTimeMillis();
        for (int i = 0; i < LOOP_COUNT; i++) {
            logger.info("hello world");
        }
        long endTime = System.currentTimeMillis();
        return "Logged messages in " + (endTime - startTime) + " ms";
    }
}

My logback.xml configuration is below:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">
    
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/happyTest.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>logs/happyTest.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>
    
    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <discardingThreshold>0</discardingThreshold>
        <queueSize>8192</queueSize>
        <appender-ref ref="FILE"/>
    </appender>
    
    <root level="INFO">
        <appender-ref ref="ASYNC"/>
    </root>
</configuration>

I use JMeter in other computer, use CLI mode run this test plan. Note that every different API just change the request path to test. Based on my understanding, the performance of System.out and System.err should be similar and generally lower than logger.info due to I configure the ch.qos.logback.classic.AsyncAppender in logback.xml.
Yes, it worked as I expected. logger.info is best.
Hower I was surprised to find that the performance of System.err is significantly lower than System.out.
Here is System.err performance. Significantly slower. Here is System.out performence. Faster compared to System.err. After reviewing the source code of System.java, I noticed that the different of System.out and System.err only is the encode and file descriptor. Both they are BufferedOutputStream, not like some AI claims that System.err is unbufferd.

// java.lang.System
// ... other code
public final static PrintStream out = null;
public final static PrintStream err = null;
// ... other code
private static void initializeSystemClass() {
    // ... other code
    FileInputStream fdIn = new FileInputStream(FileDescriptor.in);
    FileOutputStream fdOut = new FileOutputStream(FileDescriptor.out);
    FileOutputStream fdErr = new FileOutputStream(FileDescriptor.err);
    setIn0(new BufferedInputStream(fdIn));
    setOut0(newPrintStream(fdOut, props.getProperty("sun.stdout.encoding")));
    setErr0(newPrintStream(fdErr, props.getProperty("sun.stderr.encoding")));
    // ... other code
}
// ... other code
private static PrintStream newPrintStream(FileOutputStream fos, String enc) {
   if (enc != null) {
        try {
            return new PrintStream(new BufferedOutputStream(fos, 128), true, enc);
        } catch (UnsupportedEncodingException uee) {}
    }
    return new PrintStream(new BufferedOutputStream(fos, 128), true);
}

So, why is the performance of System.err is significantly lower than System.out?
Thank you for your insights!

发布评论

评论列表(0)

  1. 暂无评论