System.out.println in static initializer apparently outputting twice

Viewed 100

In my application deployed on Tomcat, there is a class as follows:

import java.util.logging.Level;
import java.util.logging.Logger;

public abstract class ServiceEndpointApplication extends Application {

    final static String LOGGER_NAME = "test";

    static {
        System.out.println("static init start");
        Logger logger = Logger.getLogger(LOGGER_NAME);
        logger.setLevel(Level.OFF);
        System.out.println("static init end");
    }
    ...
}

Just after starting up Tomcat, I send 50 reqests by using JMeter (50 threads, 1 ramp-up period, 1 loop).

Then tail -f catalina.out shows the following logs:

Nov 06, 2018 1:36:57 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 64126 ms
static init start
static init end
static init end

static init end is shown twice!

This behavior happens at a probability of about 10%.

My Question:

What are possible reasons for this strange behavior?

Environment:

  • Java

    • java version "1.7.0_80"
    • Java(TM) SE Runtime Environment (build 1.7.0_80-b15)
    • Java HotSpot(TM) 64-Bit Server VM (build 24.80-b11, mixed mode)
  • Tomcat 7.0.59

1 Answers

I found out the reason. This is caused by -f option of tail command.

I reproduced this behavior:

$ tail -f catalina.out
  ...
Nov 06, 2018 7:18:17 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 62601 ms
static init start
static init end
static init end

And then I ran tail without any options:

$ tail catalina.out 
  ...
Nov 06, 2018 7:18:17 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 62601 ms
static init start
static init end
Related