[Java] Upgrade log4j (#16657)

java/BUILD.bazel

@@ -40,11 +40,14 @@ define_java_module(
     name = "api",
     visibility = ["//visibility:public"],
     deps = [
+        "@maven//:com_lmax_disruptor",
         "@maven//:com_sun_xml_bind_jaxb_core",
         "@maven//:com_sun_xml_bind_jaxb_impl",
         "@maven//:javax_xml_bind_jaxb_api",
-        "@maven//:log4j_log4j",
-        "@maven//:org_slf4j_slf4j_log4j12",
+        "@maven//:org_apache_logging_log4j_log4j_api",
+        "@maven//:org_apache_logging_log4j_log4j_core",
+        "@maven//:org_apache_logging_log4j_log4j_slf4j_impl",
+        "@maven//:org_slf4j_slf4j_api",
     ],
 )
 
@@ -74,16 +77,18 @@ define_java_module(
         "@maven//:com_google_code_gson_gson",
         "@maven//:com_google_guava_guava",
         "@maven//:com_google_protobuf_protobuf_java",
+        "@maven//:com_lmax_disruptor",
         "@maven//:com_typesafe_config",
         "@maven//:commons_io_commons_io",
         "@maven//:de_ruedigermoeller_fst",
-        "@maven//:log4j_log4j",
         "@maven//:net_java_dev_jna_jna",
         "@maven//:org_apache_commons_commons_lang3",
+        "@maven//:org_apache_logging_log4j_log4j_api",
+        "@maven//:org_apache_logging_log4j_log4j_core",
+        "@maven//:org_apache_logging_log4j_log4j_slf4j_impl",
         "@maven//:org_msgpack_msgpack_core",
         "@maven//:org_ow2_asm_asm",
         "@maven//:org_slf4j_slf4j_api",
-        "@maven//:org_slf4j_slf4j_log4j12",
         "@maven//:org_testng_testng",
         "@maven//:org_yaml_snakeyaml",
         "@maven//:redis_clients_jedis",
@@ -98,11 +103,15 @@ define_java_module(
         "@maven//:com_google_code_gson_gson",
         "@maven//:com_google_guava_guava",
         "@maven//:com_google_protobuf_protobuf_java",
+        "@maven//:com_lmax_disruptor",
         "@maven//:com_sun_xml_bind_jaxb_core",
         "@maven//:com_sun_xml_bind_jaxb_impl",
         "@maven//:commons_io_commons_io",
         "@maven//:javax_xml_bind_jaxb_api",
         "@maven//:org_apache_commons_commons_lang3",
+        "@maven//:org_apache_logging_log4j_log4j_api",
+        "@maven//:org_apache_logging_log4j_log4j_core",
+        "@maven//:org_apache_logging_log4j_log4j_slf4j_impl",
         "@maven//:org_slf4j_slf4j_api",
         "@maven//:org_testng_testng",
     ],
@@ -115,8 +124,12 @@ define_java_module(
         ":io_ray_ray_runtime",
         "@maven//:com_google_code_gson_gson",
         "@maven//:com_google_guava_guava",
+        "@maven//:com_lmax_disruptor",
         "@maven//:commons_io_commons_io",
         "@maven//:org_apache_commons_commons_lang3",
+        "@maven//:org_apache_logging_log4j_log4j_api",
+        "@maven//:org_apache_logging_log4j_log4j_core",
+        "@maven//:org_apache_logging_log4j_log4j_slf4j_impl",
         "@maven//:org_slf4j_slf4j_api",
     ],
 )

java/api/pom.xml

@@ -17,6 +17,11 @@
   <packaging>jar</packaging>
 
   <dependencies>
+<dependency>
+  <groupId>com.lmax</groupId>
+  <artifactId>disruptor</artifactId>
+  <version>3.3.4</version>
+</dependency>
 <dependency>
   <groupId>com.sun.xml.bind</groupId>
   <artifactId>jaxb-core</artifactId>
@@ -33,13 +38,23 @@
   <version>2.3.0</version>
 </dependency>
 <dependency>
-  <groupId>log4j</groupId>
-  <artifactId>log4j</artifactId>
-  <version>1.2.17</version>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-api</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-core</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-slf4j-impl</artifactId>
+  <version>2.14.0</version>
 </dependency>
 <dependency>
   <groupId>org.slf4j</groupId>
-  <artifactId>slf4j-log4j12</artifactId>
+  <artifactId>slf4j-api</artifactId>
   <version>1.7.25</version>
 </dependency>
   </dependencies>

java/dependencies.bzl

@@ -17,7 +17,11 @@ def gen_java_deps():
             "org.apache.commons:commons-lang3:3.4",
             "org.msgpack:msgpack-core:0.8.20",
             "org.ow2.asm:asm:6.0",
-            "org.slf4j:slf4j-log4j12:1.7.25",
+            "org.apache.logging.log4j:log4j-api:2.14.0",
+            "org.apache.logging.log4j:log4j-core:2.14.0",
+            "org.apache.logging.log4j:log4j-slf4j-impl:2.14.0",
+            "org.slf4j:slf4j-api:1.7.25",
+            "com.lmax:disruptor:3.3.4",
             "org.yaml:snakeyaml:1.26",
             "redis.clients:jedis:2.8.0",
             "net.java.dev.jna:jna:5.5.0",

java/performance_test/pom.xml

@@ -37,6 +37,11 @@
   <artifactId>guava</artifactId>
   <version>30.0-jre</version>
 </dependency>
+<dependency>
+  <groupId>com.lmax</groupId>
+  <artifactId>disruptor</artifactId>
+  <version>3.3.4</version>
+</dependency>
 <dependency>
   <groupId>commons-io</groupId>
   <artifactId>commons-io</artifactId>
@@ -47,6 +52,21 @@
   <artifactId>commons-lang3</artifactId>
   <version>3.4</version>
 </dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-api</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-core</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-slf4j-impl</artifactId>
+  <version>2.14.0</version>
+</dependency>
 <dependency>
   <groupId>org.slf4j</groupId>
   <artifactId>slf4j-api</artifactId>

java/runtime/pom.xml

@@ -54,6 +54,11 @@
   <artifactId>protobuf-java</artifactId>
   <version>3.16.0</version>
 </dependency>
+<dependency>
+  <groupId>com.lmax</groupId>
+  <artifactId>disruptor</artifactId>
+  <version>3.3.4</version>
+</dependency>
 <dependency>
   <groupId>com.typesafe</groupId>
   <artifactId>config</artifactId>
@@ -74,11 +79,6 @@
   <artifactId>jaxb-api</artifactId>
   <version>2.3.0</version>
 </dependency>
-<dependency>
-  <groupId>log4j</groupId>
-  <artifactId>log4j</artifactId>
-  <version>1.2.17</version>
-</dependency>
 <dependency>
   <groupId>net.java.dev.jna</groupId>
   <artifactId>jna</artifactId>
@@ -89,6 +89,21 @@
   <artifactId>commons-lang3</artifactId>
   <version>3.4</version>
 </dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-api</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-core</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-slf4j-impl</artifactId>
+  <version>2.14.0</version>
+</dependency>
 <dependency>
   <groupId>org.msgpack</groupId>
   <artifactId>msgpack-core</artifactId>
@@ -104,11 +119,6 @@
   <artifactId>slf4j-api</artifactId>
   <version>1.7.25</version>
 </dependency>
-<dependency>
-  <groupId>org.slf4j</groupId>
-  <artifactId>slf4j-log4j12</artifactId>
-  <version>1.7.25</version>
-</dependency>
 <dependency>
   <groupId>org.testng</groupId>
   <artifactId>testng</artifactId>

java/runtime/src/main/java/io/ray/runtime/util/LoggingUtil.java

@@ -3,12 +3,17 @@ package io.ray.runtime.util;
 import com.typesafe.config.Config;
 import io.ray.runtime.config.RayConfig;
 import io.ray.runtime.generated.Common.WorkerType;
-import org.apache.log4j.ConsoleAppender;
-import org.apache.log4j.Level;
-import org.apache.log4j.Logger;
-import org.apache.log4j.PatternLayout;
-import org.apache.log4j.RollingFileAppender;
-import org.apache.log4j.WriterAppender;
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.core.LoggerContext;
+import org.apache.logging.log4j.core.appender.ConsoleAppender;
+import org.apache.logging.log4j.core.config.Configurator;
+import org.apache.logging.log4j.core.config.builder.api.AppenderComponentBuilder;
+import org.apache.logging.log4j.core.config.builder.api.ComponentBuilder;
+import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder;
+import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory;
+import org.apache.logging.log4j.core.config.builder.api.LayoutComponentBuilder;
+import org.apache.logging.log4j.core.config.builder.api.RootLoggerComponentBuilder;
+import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration;
 
 public class LoggingUtil {
 
@@ -20,28 +25,76 @@ public class LoggingUtil {
     }
     setup = true;
 
-    WriterAppender appender;
+    LoggerContext.getContext().reconfigure();
     Config config = rayConfig.getInternalConfig();
+
     if (rayConfig.workerMode == WorkerType.DRIVER) {
       // Logs of drivers are printed to console.
-      appender = new ConsoleAppender();
-      appender.setName("console");
+      ConfigurationBuilder<BuiltConfiguration> builder =
+          ConfigurationBuilderFactory.newConfigurationBuilder();
+
+      builder.setStatusLevel(Level.DEBUG);
+      builder.setConfigurationName("DefaultLogger");
+
+      // create a console appender
+      AppenderComponentBuilder appenderBuilder =
+          builder
+              .newAppender("Console", "CONSOLE")
+              .addAttribute("target", ConsoleAppender.Target.SYSTEM_OUT);
+      appenderBuilder.add(
+          builder
+              .newLayout("PatternLayout")
+              .addAttribute("pattern", config.getString("ray.logging.pattern")));
+      RootLoggerComponentBuilder rootLogger = builder.newRootLogger(Level.DEBUG);
+      rootLogger.add(builder.newAppenderRef("Console"));
+
+      builder.add(appenderBuilder);
+      rootLogger.add(builder.newAppenderRef("LogToRollingFile"));
+      builder.add(rootLogger);
+      Configurator.reconfigure(builder.build());
+
     } else {
       // Logs of workers are printed to files.
-      RollingFileAppender rfAppender = new RollingFileAppender();
-      appender = rfAppender;
+      String jobIdHex = System.getenv("RAY_JOB_ID");
+      String logPath =
+          rayConfig.logDir + "/java-worker-" + jobIdHex + "-" + SystemUtil.pid() + ".log";
+      String rollingLogPath =
+          rayConfig.logDir + "/java-worker-" + jobIdHex + "-" + SystemUtil.pid() + ".%i.log";
 
-      rfAppender.setName("file");
-      String logPath = rayConfig.logDir + "/java-worker-" + SystemUtil.pid() + ".log";
-      rfAppender.setFile(logPath);
-      rfAppender.setMaxFileSize(config.getString("ray.logging.max-file-size"));
-      rfAppender.setMaxBackupIndex(config.getInt("ray.logging.max-backup-files"));
+      ConfigurationBuilder<BuiltConfiguration> builder =
+          ConfigurationBuilderFactory.newConfigurationBuilder();
+      builder.setStatusLevel(Level.DEBUG);
+      builder.setConfigurationName("DefaultLogger");
+
+      // TODO(qwang): We can use rayConfig.logLevel instead.
+      Level level = Level.toLevel(config.getString("ray.logging.level"));
+      RootLoggerComponentBuilder rootLogger = builder.newAsyncRootLogger(level);
+      rootLogger.addAttribute("RingBufferSize", "1048576");
+      // Create a rolling file appender.
+      LayoutComponentBuilder layoutBuilder =
+          builder
+              .newLayout("PatternLayout")
+              .addAttribute("pattern", config.getString("ray.logging.pattern"));
+      ComponentBuilder triggeringPolicy =
+          builder
+              .newComponent("Policies")
+              .addComponent(
+                  builder
+                      .newComponent("SizeBasedTriggeringPolicy")
+                      .addAttribute(
+                          "size",
+                          rayConfig.getInternalConfig().getString("ray.logging.max-file-size")));
+      AppenderComponentBuilder appenderBuilder =
+          builder
+              .newAppender("LogToRollingFile", "RollingFile")
+              .addAttribute("fileName", logPath)
+              .addAttribute("filePattern", rollingLogPath)
+              .add(layoutBuilder)
+              .addComponent(triggeringPolicy);
+      builder.add(appenderBuilder);
+      rootLogger.add(builder.newAppenderRef("LogToRollingFile"));
+      builder.add(rootLogger);
+      Configurator.reconfigure(builder.build());
     }
-    Level level = Level.toLevel(config.getString("ray.logging.level"));
-    appender.setThreshold(level);
-    PatternLayout patternLayout = new PatternLayout(config.getString("ray.logging.pattern"));
-    appender.setLayout(patternLayout);
-    appender.activateOptions();
-    Logger.getLogger("io.ray").addAppender(appender);
   }
 }

java/test/pom.xml

@@ -46,6 +46,11 @@
   <artifactId>protobuf-java</artifactId>
   <version>3.16.0</version>
 </dependency>
+<dependency>
+  <groupId>com.lmax</groupId>
+  <artifactId>disruptor</artifactId>
+  <version>3.3.4</version>
+</dependency>
 <dependency>
   <groupId>com.sun.xml.bind</groupId>
   <artifactId>jaxb-core</artifactId>
@@ -71,6 +76,21 @@
   <artifactId>commons-lang3</artifactId>
   <version>3.4</version>
 </dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-api</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-core</artifactId>
+  <version>2.14.0</version>
+</dependency>
+<dependency>
+  <groupId>org.apache.logging.log4j</groupId>
+  <artifactId>log4j-slf4j-impl</artifactId>
+  <version>2.14.0</version>
+</dependency>
 <dependency>
   <groupId>org.slf4j</groupId>
   <artifactId>slf4j-api</artifactId>

java/test/src/main/java/io/ray/test/LoggingPerfTest.java

@@ -0,0 +1,33 @@
+package io.ray.test;
+
+import io.ray.api.ActorHandle;
+import io.ray.api.ObjectRef;
+import io.ray.api.Ray;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.testng.annotations.Test;
+
+public class LoggingPerfTest extends BaseTest {
+
+  private static final Logger LOG = LoggerFactory.getLogger(LoggingPerfTest.class);
+
+  private static class LoggingPerfActor {
+
+    public Long measure() {
+      final int count = 2000000;
+      final long startMs = System.currentTimeMillis();
+      for (int i = 0; i < count; ++i) {
+        LOG.info("hello world");
+      }
+      final long endMs = System.currentTimeMillis();
+      return endMs - startMs;
+    }
+  }
+
+  @Test
+  public void testLoggingPerf() {
+    ActorHandle<LoggingPerfActor> actor = Ray.actor(LoggingPerfActor::new).remote();
+    ObjectRef<Long> took = actor.task(LoggingPerfActor::measure).remote();
+    LOG.info("It took {} milliseconds.", took.get());
+  }
+}

java/test/src/main/java/io/ray/test/RayJavaLoggingTest.java

@@ -0,0 +1,50 @@
+package io.ray.test;
+
+import com.google.common.collect.ImmutableList;
+import io.ray.api.ActorHandle;
+import io.ray.api.Ray;
+import io.ray.api.id.JobId;
+import io.ray.runtime.util.SystemUtil;
+import java.io.File;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.testng.Assert;
+import org.testng.annotations.Test;
+
+@Test(groups = {"cluster"})
+public class RayJavaLoggingTest extends BaseTest {
+
+  private static final Logger LOG = LoggerFactory.getLogger(RayJavaLoggingTest.class);
+
+  private static class HeavyLoggingActor {
+    public int getPid() {
+      return SystemUtil.pid();
+    }
+
+    public boolean log() {
+      for (int i = 0; i < 100000; ++i) {
+        LOG.info("hello world, this is a log.");
+      }
+      return true;
+    }
+  }
+
+  @Test
+  public void testJavaLoggingRotate() {
+    ActorHandle<HeavyLoggingActor> loggingActor =
+        Ray.actor(HeavyLoggingActor::new)
+            .setJvmOptions(ImmutableList.of("-Dray.logging.max-file-size=1MB"))
+            .remote();
+    Assert.assertTrue(loggingActor.task(HeavyLoggingActor::log).remote().get());
+    final int pid = loggingActor.task(HeavyLoggingActor::getPid).remote().get();
+    final JobId jobId = Ray.getRuntimeContext().getCurrentJobId();
+    String currLogDir = "/tmp/ray/session_latest/logs";
+    for (int i = 1; i < 8; ++i) {
+      File rotatedFile =
+          new File(String.format("%s/java-worker-%s-%d.%d.log", currLogDir, jobId, pid, i));
+      Assert.assertTrue(rotatedFile.exists());
+      long fileSize = rotatedFile.length();
+      Assert.assertTrue(fileSize > 1024 * 1024 && fileSize < 1024 * (1024 + 1));
+    }
+  }
+}