Complete Elasticsearch logger names

This commit modifies the logger names within Elasticsearch to be the
fully-qualified class name as opposed removing the org.elasticsearch
prefix and dropping the class name. This change separates the root
logger from the Elasticsearch loggers (they were equated from the
removal of the org.elasticsearch prefix) and enables log levels to be
set at the class level (instead of the package level).

Relates #20457

core/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java

@@ -42,21 +42,23 @@ private ESLoggerFactory() {
             Property.Dynamic, Property.NodeScope);
 
     public static Logger getLogger(String prefix, String name) {
-        name = name.intern();
-        final Logger logger = LogManager.getLogger(name);
-        return new PrefixLogger((ExtendedLogger)logger, name, prefix);
+        return getLogger(prefix, LogManager.getLogger(name));
     }
 
-    public static Logger getLogger(String name) {
-        return getLogger(null, name);
+    public static Logger getLogger(String prefix, Class<?> clazz) {
+        return getLogger(prefix, LogManager.getLogger(clazz));
+    }
+
+    public static Logger getLogger(String prefix, Logger logger) {
+        return new PrefixLogger((ExtendedLogger)logger, logger.getName(), prefix);
     }
 
-    public static DeprecationLogger getDeprecationLogger(String name) {
-        return new DeprecationLogger(getLogger(name));
+    public static Logger getLogger(Class<?> clazz) {
+        return getLogger(null, clazz);
     }
 
-    public static DeprecationLogger getDeprecationLogger(String prefix, String name) {
-        return new DeprecationLogger(getLogger(prefix, name));
+    public static Logger getLogger(String name) {
+        return getLogger(null, name);
     }
 
     public static Logger getRootLogger() {

core/src/main/java/org/elasticsearch/common/logging/Loggers.java

@@ -48,24 +48,8 @@
  */
 public class Loggers {
 
-    static final String commonPrefix = System.getProperty("es.logger.prefix", "org.elasticsearch.");
-
     public static final String SPACE = " ";
 
-    private static boolean consoleLoggingEnabled = true;
-
-    public static void disableConsoleLogging() {
-        consoleLoggingEnabled = false;
-    }
-
-    public static void enableConsoleLogging() {
-        consoleLoggingEnabled = true;
-    }
-
-    public static boolean consoleLoggingEnabled() {
-        return consoleLoggingEnabled;
-    }
-
     public static Logger getLogger(Class<?> clazz, Settings settings, ShardId shardId, String... prefixes) {
         return getLogger(clazz, settings, shardId.getIndex(), asArrayList(Integer.toString(shardId.id()), prefixes).toArray(new String[0]));
     }
@@ -84,38 +68,48 @@ public static Logger getLogger(Class<?> clazz, Settings settings, Index index, S
     }
 
     public static Logger getLogger(Class<?> clazz, Settings settings, String... prefixes) {
-        return getLogger(buildClassLoggerName(clazz), settings, prefixes);
+        final List<String> prefixesList = prefixesList(settings, prefixes);
+        return getLogger(clazz, prefixesList.toArray(new String[prefixesList.size()]));
     }
 
     public static Logger getLogger(String loggerName, Settings settings, String... prefixes) {
+        final List<String> prefixesList = prefixesList(settings, prefixes);
+        return getLogger(loggerName, prefixesList.toArray(new String[prefixesList.size()]));
+    }
+
+    private static List<String> prefixesList(Settings settings, String... prefixes) {
         List<String> prefixesList = new ArrayList<>();
         if (Node.NODE_NAME_SETTING.exists(settings)) {
             prefixesList.add(Node.NODE_NAME_SETTING.get(settings));
         }
         if (prefixes != null && prefixes.length > 0) {
             prefixesList.addAll(asList(prefixes));
         }
-        return getLogger(getLoggerName(loggerName), prefixesList.toArray(new String[prefixesList.size()]));
+        return prefixesList;
     }
 
     public static Logger getLogger(Logger parentLogger, String s) {
         assert parentLogger instanceof PrefixLogger;
-        return ESLoggerFactory.getLogger(((PrefixLogger)parentLogger).prefix(), getLoggerName(parentLogger.getName() + s));
+        return ESLoggerFactory.getLogger(((PrefixLogger)parentLogger).prefix(), parentLogger.getName() + s);
     }
 
     public static Logger getLogger(String s) {
-        return ESLoggerFactory.getLogger(getLoggerName(s));
+        return ESLoggerFactory.getLogger(s);
     }
 
     public static Logger getLogger(Class<?> clazz) {
-        return ESLoggerFactory.getLogger(getLoggerName(buildClassLoggerName(clazz)));
+        return ESLoggerFactory.getLogger(clazz);
     }
 
     public static Logger getLogger(Class<?> clazz, String... prefixes) {
-        return getLogger(buildClassLoggerName(clazz), prefixes);
+        return ESLoggerFactory.getLogger(formatPrefix(prefixes), clazz);
     }
 
     public static Logger getLogger(String name, String... prefixes) {
+        return ESLoggerFactory.getLogger(formatPrefix(prefixes), name);
+    }
+
+    private static String formatPrefix(String... prefixes) {
         String prefix = null;
         if (prefixes != null && prefixes.length > 0) {
             StringBuilder sb = new StringBuilder();
@@ -133,7 +127,7 @@ public static Logger getLogger(String name, String... prefixes) {
                 prefix = sb.toString();
             }
         }
-        return ESLoggerFactory.getLogger(prefix, getLoggerName(name));
+        return prefix;
     }
 
     /**
@@ -170,21 +164,6 @@ public static void setLevel(Logger logger, Level level) {
         }
     }
 
-    private static String buildClassLoggerName(Class<?> clazz) {
-        String name = clazz.getName();
-        if (name.startsWith("org.elasticsearch.")) {
-            name = Classes.getPackageName(clazz);
-        }
-        return name;
-    }
-
-    private static String getLoggerName(String name) {
-        if (name.startsWith("org.elasticsearch.")) {
-            name = name.substring("org.elasticsearch.".length());
-        }
-        return commonPrefix + name;
-    }
-
     public static void addAppender(final Logger logger, final Appender appender) {
         final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
         final Configuration config = ctx.getConfiguration();

core/src/main/java/org/elasticsearch/common/lucene/LoggerInfoStream.java

@@ -25,19 +25,12 @@
 
 /** An InfoStream (for Lucene's IndexWriter) that redirects
  *  messages to "lucene.iw.ifd" and "lucene.iw" Logger.trace. */
-
 public final class LoggerInfoStream extends InfoStream {
-    /** Used for component-specific logging: */
-
-    /** Logger for everything */
-    private final Logger logger;
 
-    /** Logger for IndexFileDeleter */
-    private final Logger ifdLogger;
+    private final Logger parentLogger;
 
-    public LoggerInfoStream(Logger parentLogger) {
-        logger = Loggers.getLogger(parentLogger, ".lucene.iw");
-        ifdLogger = Loggers.getLogger(parentLogger, ".lucene.iw.ifd");
+    public LoggerInfoStream(final Logger parentLogger) {
+        this.parentLogger = parentLogger;
     }
 
     @Override
@@ -53,14 +46,11 @@ public boolean isEnabled(String component) {
     }
 
     private Logger getLogger(String component) {
-        if (component.equals("IFD")) {
-            return ifdLogger;
-        } else {
-            return logger;
-        }
+        return Loggers.getLogger(parentLogger, "." + component);
     }
 
     @Override
     public void close() {
+
     }
 }

core/src/test/java/org/elasticsearch/action/admin/indices/shards/IndicesShardStoreRequestIT.java

@@ -60,7 +60,7 @@
 import static org.hamcrest.Matchers.nullValue;
 
 @ESIntegTestCase.ClusterScope(scope = ESIntegTestCase.Scope.TEST)
-@TestLogging("_root:DEBUG,action.admin.indices.shards:TRACE,cluster.service:TRACE")
+@TestLogging("_root:DEBUG,org.elasticsearch.action.admin.indices.shards:TRACE,org.elasticsearch.cluster.service:TRACE")
 public class IndicesShardStoreRequestIT extends ESIntegTestCase {
 
     @Override

core/src/test/java/org/elasticsearch/bwcompat/RepositoryUpgradabilityIT.java

@@ -47,7 +47,7 @@
  */
 @ESIntegTestCase.ClusterScope(scope = ESIntegTestCase.Scope.TEST)
 // this test sometimes fails in recovery when the recovery is reset, increasing the logging level to help debug
-@TestLogging("indices.recovery:DEBUG")
+@TestLogging("org.elasticsearch.indices.recovery:DEBUG")
 public class RepositoryUpgradabilityIT extends AbstractSnapshotIntegTestCase {
 
     /**

core/src/test/java/org/elasticsearch/cluster/MinimumMasterNodesIT.java

@@ -65,7 +65,7 @@
 
 @ClusterScope(scope = Scope.TEST, numDataNodes = 0)
 @ESIntegTestCase.SuppressLocalMode
-@TestLogging("_root:DEBUG,cluster.service:TRACE,discovery.zen:TRACE")
+@TestLogging("_root:DEBUG,org.elasticsearch.cluster.service:TRACE,org.elasticsearch.discovery.zen:TRACE")
 public class MinimumMasterNodesIT extends ESIntegTestCase {
 
     @Override

core/src/test/java/org/elasticsearch/cluster/service/ClusterServiceIT.java

@@ -363,7 +363,7 @@ public void onFailure(String source, Exception e) {
         assertThat(processedLatch.await(1, TimeUnit.SECONDS), equalTo(true));
     }
 
-    @TestLogging("_root:debug,action.admin.cluster.tasks:trace")
+    @TestLogging("_root:debug,org.elasticsearch.action.admin.cluster.tasks:trace")
     public void testPendingUpdateTask() throws Exception {
         Settings settings = Settings.builder()
                 .put("discovery.type", "local")

core/src/test/java/org/elasticsearch/cluster/service/ClusterServiceTests.java

@@ -677,18 +677,30 @@ public void onFailure(String source, Exception e) {
         latch.await();
     }
 
-    @TestLogging("cluster:TRACE") // To ensure that we log cluster state events on TRACE level
+    @TestLogging("org.elasticsearch.cluster.service:TRACE") // To ensure that we log cluster state events on TRACE level
     public void testClusterStateUpdateLogging() throws Exception {
         MockLogAppender mockAppender = new MockLogAppender();
-        mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test1", "cluster.service", Level.DEBUG,
-            "*processing [test1]: took [1s] no change in cluster_state"));
-        mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test2", "cluster.service", Level.TRACE,
-            "*failed to execute cluster state update in [2s]*"));
-        mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test3", "cluster.service", Level.DEBUG,
-            "*processing [test3]: took [3s] done applying updated cluster_state (version: *, uuid: *)"));
-
-        Logger rootLogger = LogManager.getRootLogger();
-        Loggers.addAppender(rootLogger, mockAppender);
+        mockAppender.addExpectation(
+                new MockLogAppender.SeenEventExpectation(
+                        "test1",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.DEBUG,
+                        "*processing [test1]: took [1s] no change in cluster_state"));
+        mockAppender.addExpectation(
+                new MockLogAppender.SeenEventExpectation(
+                        "test2",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.TRACE,
+                        "*failed to execute cluster state update in [2s]*"));
+        mockAppender.addExpectation(
+                new MockLogAppender.SeenEventExpectation(
+                        "test3",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.DEBUG,
+                        "*processing [test3]: took [3s] done applying updated cluster_state (version: *, uuid: *)"));
+
+        Logger clusterLogger = Loggers.getLogger("org.elasticsearch.cluster.service");
+        Loggers.addAppender(clusterLogger, mockAppender);
         try {
             final CountDownLatch latch = new CountDownLatch(4);
             clusterService.currentTimeOverride = System.nanoTime();
@@ -743,7 +755,7 @@ public void onFailure(String source, Exception e) {
                     fail();
                 }
             });
-            // Additional update task to make sure all previous logging made it to the logger
+            // Additional update task to make sure all previous logging made it to the loggerName
             // We don't check logging for this on since there is no guarantee that it will occur before our check
             clusterService.submitStateUpdateTask("test4", new ClusterStateUpdateTask() {
                 @Override
@@ -763,25 +775,41 @@ public void onFailure(String source, Exception e) {
             });
             latch.await();
         } finally {
-            Loggers.removeAppender(rootLogger, mockAppender);
+            Loggers.removeAppender(clusterLogger, mockAppender);
         }
         mockAppender.assertAllExpectationsMatched();
     }
 
-    @TestLogging("cluster:WARN") // To ensure that we log cluster state events on WARN level
+    @TestLogging("org.elasticsearch.cluster.service:WARN") // To ensure that we log cluster state events on WARN level
     public void testLongClusterStateUpdateLogging() throws Exception {
         MockLogAppender mockAppender = new MockLogAppender();
-        mockAppender.addExpectation(new MockLogAppender.UnseenEventExpectation("test1 shouldn't see because setting is too low",
-            "cluster.service", Level.WARN, "*cluster state update task [test1] took [*] above the warn threshold of *"));
-        mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test2", "cluster.service", Level.WARN,
-            "*cluster state update task [test2] took [32s] above the warn threshold of *"));
-        mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test3", "cluster.service", Level.WARN,
-            "*cluster state update task [test3] took [33s] above the warn threshold of *"));
-        mockAppender.addExpectation(new MockLogAppender.SeenEventExpectation("test4", "cluster.service", Level.WARN,
-            "*cluster state update task [test4] took [34s] above the warn threshold of *"));
-
-        Logger rootLogger = LogManager.getRootLogger();
-        Loggers.addAppender(rootLogger, mockAppender);
+        mockAppender.addExpectation(
+                new MockLogAppender.UnseenEventExpectation(
+                        "test1 shouldn't see because setting is too low",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.WARN,
+                        "*cluster state update task [test1] took [*] above the warn threshold of *"));
+        mockAppender.addExpectation(
+                new MockLogAppender.SeenEventExpectation(
+                        "test2",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.WARN,
+                        "*cluster state update task [test2] took [32s] above the warn threshold of *"));
+        mockAppender.addExpectation(
+                new MockLogAppender.SeenEventExpectation(
+                        "test3",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.WARN,
+                        "*cluster state update task [test3] took [33s] above the warn threshold of *"));
+        mockAppender.addExpectation(
+                new MockLogAppender.SeenEventExpectation(
+                        "test4",
+                        "org.elasticsearch.cluster.service.ClusterServiceTests$TimedClusterService",
+                        Level.WARN,
+                        "*cluster state update task [test4] took [34s] above the warn threshold of *"));
+
+        Logger clusterLogger = Loggers.getLogger("org.elasticsearch.cluster.service");
+        Loggers.addAppender(clusterLogger, mockAppender);
         try {
             final CountDownLatch latch = new CountDownLatch(5);
             final CountDownLatch processedFirstTask = new CountDownLatch(1);
@@ -857,7 +885,7 @@ public void onFailure(String source, Exception e) {
                     fail();
                 }
             });
-            // Additional update task to make sure all previous logging made it to the logger
+            // Additional update task to make sure all previous logging made it to the loggerName
             // We don't check logging for this on since there is no guarantee that it will occur before our check
             clusterService.submitStateUpdateTask("test5", new ClusterStateUpdateTask() {
                 @Override
@@ -877,7 +905,7 @@ public void onFailure(String source, Exception e) {
             });
             latch.await();
         } finally {
-            Loggers.removeAppender(rootLogger, mockAppender);
+            Loggers.removeAppender(clusterLogger, mockAppender);
         }
         mockAppender.assertAllExpectationsMatched();
     }

core/src/test/java/org/elasticsearch/discovery/DiscoveryWithServiceDisruptionsIT.java

@@ -118,7 +118,7 @@
 
 @ClusterScope(scope = Scope.TEST, numDataNodes = 0, transportClientRatio = 0)
 @ESIntegTestCase.SuppressLocalMode
-@TestLogging("_root:DEBUG,cluster.service:TRACE")
+@TestLogging("_root:DEBUG,org.elasticsearch.cluster.service:TRACE")
 public class DiscoveryWithServiceDisruptionsIT extends ESIntegTestCase {
 
     private static final TimeValue DISRUPTION_HEALING_OVERHEAD = TimeValue.timeValueSeconds(40); // we use 30s as timeout in many places.
@@ -384,7 +384,7 @@ public void testVerifyApiBlocksDuringPartition() throws Exception {
      * This test isolates the master from rest of the cluster, waits for a new master to be elected, restores the partition
      * and verifies that all node agree on the new cluster state
      */
-    @TestLogging("_root:DEBUG,cluster.service:TRACE,gateway:TRACE,indices.store:TRACE")
+    @TestLogging("_root:DEBUG,org.elasticsearch.cluster.service:TRACE,org.elasticsearch.gateway:TRACE,org.elasticsearch.indices.store:TRACE")
     public void testIsolateMasterAndVerifyClusterStateConsensus() throws Exception {
         final List<String> nodes = startCluster(3);
 
@@ -454,8 +454,8 @@ public void testIsolateMasterAndVerifyClusterStateConsensus() throws Exception {
      * <p>
      * This test is a superset of tests run in the Jepsen test suite, with the exception of versioned updates
      */
-    @TestLogging("_root:DEBUG,action.index:TRACE,action.get:TRACE,discovery:TRACE,cluster.service:TRACE,"
-            + "indices.recovery:TRACE,indices.cluster:TRACE")
+    @TestLogging("_root:DEBUG,org.elasticsearch.action.index:TRACE,org.elasticsearch.action.get:TRACE,discovery:TRACE,org.elasticsearch.cluster.service:TRACE,"
+            + "org.elasticsearch.indices.recovery:TRACE,org.elasticsearch.indices.cluster:TRACE")
     public void testAckedIndexing() throws Exception {
 
         final int seconds = !(TEST_NIGHTLY && rarely()) ? 1 : 5;
@@ -636,7 +636,7 @@ public void testMasterNodeGCs() throws Exception {
      * that already are following another elected master node. These nodes should reject this cluster state and prevent
      * them from following the stale master.
      */
-    @TestLogging("_root:DEBUG,cluster.service:TRACE,test.disruption:TRACE")
+    @TestLogging("_root:DEBUG,org.elasticsearch.cluster.service:TRACE,org.elasticsearch.test.disruption:TRACE")
     public void testStaleMasterNotHijackingMajority() throws Exception {
         // 3 node cluster with unicast discovery and minimum_master_nodes set to 2:
         final List<String> nodes = startCluster(3, 2);

core/src/test/java/org/elasticsearch/discovery/zen/NodeJoinControllerTests.java

@@ -91,7 +91,7 @@
 import static org.hamcrest.Matchers.equalTo;
 import static org.hamcrest.Matchers.instanceOf;
 
-@TestLogging("discovery.zen:TRACE")
+@TestLogging("org.elasticsearch.discovery.zen:TRACE")
 public class NodeJoinControllerTests extends ESTestCase {
 
     private static ThreadPool threadPool;

core/src/test/java/org/elasticsearch/discovery/zen/publish/PublishClusterStateActionTests.java

@@ -82,7 +82,7 @@
 import static org.hamcrest.Matchers.notNullValue;
 import static org.hamcrest.Matchers.nullValue;
 
-@TestLogging("discovery.zen.publish:TRACE")
+@TestLogging("org.elasticsearch.discovery.zen.publish:TRACE")
 public class PublishClusterStateActionTests extends ESTestCase {
 
     private static final ClusterName CLUSTER_NAME = ClusterName.CLUSTER_NAME_SETTING.getDefault(Settings.EMPTY);