Elasticsearch json logging

distribution/src/config/jvm.options

@@ -120,3 +120,5 @@ ${error.file}
 
 # temporary workaround for C2 bug with JDK 10 on hardware with AVX-512
 10-:-XX:UseAVX=2
+
+-Dlog4j2.loggerContextFactory=org.elasticsearch.common.logging.MarkerLoggerContextFactory

distribution/src/config/log4j2.properties

@@ -7,14 +7,37 @@ logger.action.level = debug
 appender.console.type = Console
 appender.console.name = console
 appender.console.layout.type = PatternLayout
-appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
+appender.console.layout.pattern ={\
+  "type": "console", \
+  "timestamp": "%d{ISO8601}", \
+  "level": "%-5p", \
+  "class": "%c{1.}", \
+  "cluster_name": ${sys:es.logs.cluster_name}", \
+  "node_name": "%node_name", \
+  "node_id": "%node_id_raw", \
+  %marker\
+  "message": "%.-10000m"\
+  }%n
 
 appender.rolling.type = RollingFile
 appender.rolling.name = rolling
 appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log
 appender.rolling.layout.type = PatternLayout
-appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n
+appender.rolling.layout.pattern ={\
+  "type": "rolling", \
+  "timestamp": "%d{ISO8601}", \
+  "level": "%-5p", \
+  "class": "%c{1.}", \
+  "cluster_name": ${sys:es.logs.cluster_name}", \
+  "node_name": "%node_name", \
+  "node_id": "%node_id_raw", \
+  %marker\
+  "message": "%.-10000m"\
+  }%n
 appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz
+
+
+
 appender.rolling.policies.type = Policies
 appender.rolling.policies.time.type = TimeBasedTriggeringPolicy
 appender.rolling.policies.time.interval = 1
@@ -38,7 +61,18 @@ appender.deprecation_rolling.type = RollingFile
 appender.deprecation_rolling.name = deprecation_rolling
 appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log
 appender.deprecation_rolling.layout.type = PatternLayout
-appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n
+appender.deprecation_rolling.layout.pattern = {\
+  "type": "rolling", \
+  "timestamp": "%d{ISO8601}", \
+  "level": "%-5p", \
+  "class": "%c{1.}", \
+  "cluster_name": ${sys:es.logs.cluster_name}", \
+  "node_name": "%node_name", \
+  "node_id": "%node_id_raw", \
+  %marker\
+  "message": "%.-10000m"\
+  }%n
+
 appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.log.gz
 appender.deprecation_rolling.policies.type = Policies
 appender.deprecation_rolling.policies.size.type = SizeBasedTriggeringPolicy
@@ -55,7 +89,17 @@ appender.index_search_slowlog_rolling.type = RollingFile
 appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
 appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log
 appender.index_search_slowlog_rolling.layout.type = PatternLayout
-appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n
+appender.index_search_slowlog_rolling.layout.pattern = {\
+  "type": "rolling", \
+  "timestamp": "%d{ISO8601}", \
+  "level": "%-5p", \
+  "class": "%c{1.}", \
+  "cluster_name": ${sys:es.logs.cluster_name}", \
+  "node_name": "%node_name", \
+  "node_id": "%node_id_raw", \
+  %marker\
+  "message": "%.-10000m"\
+  }%n
 appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz
 appender.index_search_slowlog_rolling.policies.type = Policies
 appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy
@@ -72,7 +116,17 @@ appender.index_indexing_slowlog_rolling.type = RollingFile
 appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling
 appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log
 appender.index_indexing_slowlog_rolling.layout.type = PatternLayout
-appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n
+appender.index_indexing_slowlog_rolling.layout.pattern = {\
+  "type": "rolling", \
+  "timestamp": "%d{ISO8601}", \
+  "level": "%-5p", \
+  "class": "%c{1.}", \
+  "cluster_name": ${sys:es.logs.cluster_name}", \
+  "node_name": "%node_name", \
+  "node_id": "%node_id_raw", \
+  %marker\
+  "message": "%.-10000m"\
+  }%n
 appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz
 appender.index_indexing_slowlog_rolling.policies.type = Policies
 appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy

plugins/discovery-ec2/build.gradle

@@ -33,8 +33,8 @@ dependencies {
   compile "org.apache.httpcomponents:httpcore:${versions.httpcore}"
   compile "commons-logging:commons-logging:${versions.commonslogging}"
   compile "commons-codec:commons-codec:${versions.commonscodec}"
-  compile 'com.fasterxml.jackson.core:jackson-databind:2.6.7.1'
-  compile 'com.fasterxml.jackson.core:jackson-annotations:2.6.0'
+  compile "com.fasterxml.jackson.core:jackson-databind:${versions.jackson}"
+  compile "com.fasterxml.jackson.core:jackson-annotations:${versions.jackson}"
 }
 
 dependencyLicenses {

plugins/repository-s3/build.gradle

@@ -46,8 +46,8 @@ dependencies {
   compile "commons-logging:commons-logging:${versions.commonslogging}"
   compile "commons-codec:commons-codec:${versions.commonscodec}"
   compile "com.fasterxml.jackson.core:jackson-core:${versions.jackson}"
-  compile 'com.fasterxml.jackson.core:jackson-databind:2.6.7.1'
-  compile 'com.fasterxml.jackson.core:jackson-annotations:2.6.0'
+  compile "com.fasterxml.jackson.core:jackson-databind:${versions.jackson}"
+  compile "com.fasterxml.jackson.core:jackson-annotations:${versions.jackson}"
   compile "com.fasterxml.jackson.dataformat:jackson-dataformat-cbor:${versions.jackson}"
   compile "joda-time:joda-time:${versions.joda}"
 

server/build.gradle

@@ -123,6 +123,10 @@ dependencies {
   // repackaged jna with native bits linked against all elastic supported platforms
   compile "org.elasticsearch:jna:${versions.jna}"
 
+  compile "com.fasterxml.jackson.core:jackson-databind:${versions.jackson}"
+  compile("com.fasterxml.jackson.core:jackson-annotations:${versions.jackson}")
+
+
   if (!isEclipse && !isIdea) {
     java9Compile sourceSets.main.output
   }

server/src/main/java/org/elasticsearch/common/logging/MarkerLogger.java

@@ -0,0 +1,181 @@
+/*
+ * Licensed to Elasticsearch under one or more contributor
+ * license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright
+ * ownership. Elasticsearch licenses this file to you under
+ * the Apache License, Version 2.0 (the "License"); you may
+ * not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.elasticsearch.common.logging;
+
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.Marker;
+import org.apache.logging.log4j.MarkerManager;
+import org.apache.logging.log4j.core.Logger;
+import org.apache.logging.log4j.core.LoggerContext;
+import org.apache.logging.log4j.message.Message;
+import org.apache.logging.log4j.message.MessageFactory;
+import org.apache.logging.log4j.spi.ExtendedLogger;
+import org.apache.logging.log4j.util.StringBuilderFormattable;
+import org.apache.logging.log4j.util.Strings;
+
+import java.util.WeakHashMap;
+import java.util.concurrent.atomic.AtomicReference;
+
+public class MarkerLogger extends Logger {
+
+
+    /*
+     * We can not use the built-in Marker tracking (MarkerManager) because the MarkerManager holds a permanent reference to the marker;
+     * however, we have transient markers from index-level and shard-level components so this would effectively be a memory leak. Since we
+     * can not tie into the lifecycle of these components, we have to use a mechanism that enables garbage collection of such markers when
+     * they are no longer in use.
+     */
+    private static final WeakHashMap<String, Marker> markers = new WeakHashMap<>();
+
+    /**
+     * Return the size of the cached markers. This size can vary as markers are cached but collected during GC activity when a given prefix
+     * is no longer in use.
+     *
+     * @return the size of the cached markers
+     */
+    static int markersSize() {
+        return markers.size();
+    }
+
+    /**
+     * The marker for this prefix logger.
+     */
+    private final Marker marker;
+
+    /**
+     * Obtain the prefix for this prefix logger. This can be used to create a logger with the same prefix as this one.
+     *
+     * @return the prefix
+     */
+    public String prefix() {
+        return marker.getName();
+    }
+
+    /**
+     * The constructor.
+     * //TODO consider what happens when UNKOWN_NODE_ID are not in use anymore
+     */
+    protected MarkerLogger(Logger logger, AtomicReference<NodeIdListener> nodeIdListener) {
+        super(logger.getContext(), logger.getName(), logger.getMessageFactory());
+        String prefix = getPrefix(nodeIdListener);
+
+        final Marker actualMarker;
+        // markers is not thread-safe, so we synchronize access
+        synchronized (markers) {
+            final Marker maybeMarker = markers.get(prefix);
+            if (maybeMarker == null) {
+                if (nodeIdListener.get() != null && Strings.isNotEmpty(nodeIdListener.get().getNodeId().get())) {
+                    actualMarker = new MarkerManager.Log4jMarker(prefix);
+                } else {
+                    actualMarker = new AtomicRefMarker(nodeIdListener);
+                }
+
+                /*
+                 * We must create a new instance here as otherwise the marker will hold a reference to the key in the weak hash map; as
+                 * those references are held strongly, this would give a strong reference back to the key preventing them from ever being
+                 * collected. This also guarantees that no other strong reference can be held to the prefix anywhere.
+                 */
+                // noinspection RedundantStringConstructorCall
+                markers.put(new String(prefix), actualMarker);
+            } else {
+                actualMarker = maybeMarker;
+            }
+        }
+        this.marker = actualMarker;
+    }
+
+    private String getPrefix(AtomicReference<NodeIdListener> nodeIdListenerRef) {
+        NodeIdListener nodeIdListener = nodeIdListenerRef.get();
+        if (nodeIdListener != null) {
+            AtomicReference<String> nodeId = nodeIdListener.getNodeId();
+            return nodeId.get();
+        }
+        return NodeIdListener.UNKOWN_NODE_ID;
+    }
+
+
+    @Override
+    public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message, final Throwable t) {
+        super.logMessage(fqcn, level, this.marker, message, t);
+    }
+
+    static class AtomicRefMarker implements Marker, StringBuilderFormattable {
+
+        private AtomicReference<NodeIdListener> nodeId;
+
+        /**
+         * Constructs a new Marker.
+         */
+        public AtomicRefMarker(AtomicReference<NodeIdListener> nodeId) {
+            this.nodeId = nodeId;
+        }
+
+        @Override
+        public String getName() {
+            if (nodeId.get() != null && Strings.isNotEmpty(nodeId.get().getNodeId().get())) {
+                return nodeId.get().getNodeId().get();
+            }
+            return NodeIdListener.UNKOWN_NODE_ID;
+        }
+
+        @Override
+        public void formatTo(StringBuilder buffer) {
+            buffer.append(getName());
+        }
+        //just using the marker for its name in logs since other methos are unimplemented
+
+        @Override
+        public Marker addParents(Marker... markers) {
+            return null;
+        }
+
+        @Override
+        public Marker[] getParents() {
+            return new Marker[0];
+        }
+
+        @Override
+        public boolean hasParents() {
+            return false;
+        }
+
+        @Override
+        public boolean isInstanceOf(Marker m) {
+            return false;
+        }
+
+        @Override
+        public boolean isInstanceOf(String name) {
+            return false;
+        }
+
+        @Override
+        public boolean remove(Marker marker) {
+            return false;
+        }
+
+        @Override
+        public Marker setParents(Marker... markers) {
+            return null;
+        }
+
+
+    }
+}

server/src/main/java/org/elasticsearch/common/logging/MarkerLoggerContext.java

@@ -0,0 +1,42 @@
+/*
+ * Licensed to Elasticsearch under one or more contributor
+ * license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright
+ * ownership. Elasticsearch licenses this file to you under
+ * the Apache License, Version 2.0 (the "License"); you may
+ * not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.elasticsearch.common.logging;
+
+import org.apache.logging.log4j.core.Logger;
+import org.apache.logging.log4j.core.LoggerContext;
+
+import java.util.concurrent.atomic.AtomicReference;
+
+public class MarkerLoggerContext extends LoggerContext {
+
+    private final AtomicReference<NodeIdListener> nodeIdListener;
+
+    public MarkerLoggerContext(String name, AtomicReference<NodeIdListener>  nodeIdListener) {
+        super(name);
+        this.nodeIdListener = nodeIdListener;
+    }
+
+    @Override
+    public Logger getLogger(final String name) {
+        Logger logger = getLogger(name, null);
+        MarkerLogger marker = new MarkerLogger(logger,nodeIdListener);
+        return marker;
+    }
+}

server/src/main/java/org/elasticsearch/common/logging/MarkerLoggerContextFactory.java

@@ -0,0 +1,37 @@
+/*
+ * Licensed to Elasticsearch under one or more contributor
+ * license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright
+ * ownership. Elasticsearch licenses this file to you under
+ * the Apache License, Version 2.0 (the "License"); you may
+ * not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.elasticsearch.common.logging;
+
+import org.apache.logging.log4j.core.impl.Log4jContextFactory;
+
+import java.util.concurrent.atomic.AtomicReference;
+
+public class MarkerLoggerContextFactory extends Log4jContextFactory {
+
+    private static final AtomicReference<NodeIdListener> nodeIdListener = new AtomicReference<>();
+
+    public MarkerLoggerContextFactory() {
+        super(new MarkerLoggerContextSelector(nodeIdListener));
+    }
+
+    public void setNodeIdListener(NodeIdListener nodeIdListener) {
+        MarkerLoggerContextFactory.nodeIdListener.set(nodeIdListener);
+    }
+}