Elasticsearch json logging

distribution/archives/integ-test-zip/build.gradle

@@ -27,7 +27,7 @@ integTestRunner {
    */
   if (System.getProperty("tests.rest.cluster") == null) {
     systemProperty 'tests.logfile',
-      "${ -> integTest.nodes[0].homeDir}/logs/${ -> integTest.nodes[0].clusterName }.log"
+      "${ -> integTest.nodes[0].homeDir}/logs/${ -> integTest.nodes[0].clusterName }_server.json"
   } else {
     systemProperty 'tests.logfile', '--external--'
   }

distribution/archives/integ-test-zip/src/test/java/org/elasticsearch/test/rest/NodeNameInLogsIT.java → distribution/archives/integ-test-zip/src/test/java/org/elasticsearch/test/rest/JsonLogsFormatAndParseIT.java

@@ -19,11 +19,11 @@
 
 package org.elasticsearch.test.rest;
 
-import org.elasticsearch.common.logging.NodeNameInLogsIntegTestCase;
+import org.elasticsearch.common.logging.JsonLogsIntegTestCase;
 import org.hamcrest.Matcher;
 
-import java.io.IOException;
 import java.io.BufferedReader;
+import java.io.IOException;
 import java.nio.charset.StandardCharsets;
 import java.nio.file.Files;
 import java.nio.file.Path;
@@ -32,7 +32,7 @@
 
 import static org.hamcrest.Matchers.is;
 
-public class NodeNameInLogsIT extends NodeNameInLogsIntegTestCase {
+public class JsonLogsFormatAndParseIT extends JsonLogsIntegTestCase {
     @Override
     protected Matcher<String> nodeNameMatcher() {
         return is("node-0");
@@ -41,7 +41,7 @@ protected Matcher<String> nodeNameMatcher() {
     @Override
     protected BufferedReader openReader(Path logFile) {
         assumeFalse("Skipping test because it is being run against an external cluster.",
-                logFile.getFileName().toString().equals("--external--"));
+            logFile.getFileName().toString().equals("--external--"));
         return AccessController.doPrivileged((PrivilegedAction<BufferedReader>) () -> {
             try {
                 return Files.newBufferedReader(logFile, StandardCharsets.UTF_8);

distribution/docker/src/docker/config/log4j2.properties

@@ -1,9 +1,43 @@
 status = error
 
-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
+# log action execution errors for easier debugging
+logger.action.name = org.elasticsearch.action
+logger.action.level = debug
+
+appender.rolling.type = Console
+appender.rolling.name = rolling
+appender.rolling.layout.type = ESJsonLayout
+appender.rolling.layout.type_name = server
 
 rootLogger.level = info
-rootLogger.appenderRef.console.ref = console
+rootLogger.appenderRef.rolling.ref = rolling
+
+appender.deprecation_rolling.type = Console
+appender.deprecation_rolling.name = deprecation_rolling
+appender.deprecation_rolling.layout.type = ESJsonLayout
+appender.deprecation_rolling.layout.type_name = deprecation
+
+logger.deprecation.name = org.elasticsearch.deprecation
+logger.deprecation.level = warn
+logger.deprecation.appenderRef.deprecation_rolling.ref = deprecation_rolling
+logger.deprecation.additivity = false
+
+appender.index_search_slowlog_rolling.type = Console
+appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
+appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
+appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
+
+logger.index_search_slowlog_rolling.name = index.search.slowlog
+logger.index_search_slowlog_rolling.level = trace
+logger.index_search_slowlog_rolling.appenderRef.index_search_slowlog_rolling.ref = index_search_slowlog_rolling
+logger.index_search_slowlog_rolling.additivity = false
+
+appender.index_indexing_slowlog_rolling.type = Console
+appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling
+appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
+appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
+
+logger.index_indexing_slowlog.name = index.indexing.slowlog.index
+logger.index_indexing_slowlog.level = trace
+logger.index_indexing_slowlog.appenderRef.index_indexing_slowlog_rolling.ref = index_indexing_slowlog_rolling
+logger.index_indexing_slowlog.additivity = false

distribution/src/config/log4j2.properties

@@ -9,12 +9,14 @@ appender.console.name = console
 appender.console.layout.type = PatternLayout
 appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
 
+######## Server JSON ############################
 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.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz
+appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_server.json
+appender.rolling.layout.type = ESJsonLayout
+appender.rolling.layout.type_name = server
+
+appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.json.gz
 appender.rolling.policies.type = Policies
 appender.rolling.policies.time.type = TimeBasedTriggeringPolicy
 appender.rolling.policies.time.interval = 1
@@ -29,58 +31,144 @@ appender.rolling.strategy.action.condition.type = IfFileName
 appender.rolling.strategy.action.condition.glob = ${sys:es.logs.cluster_name}-*
 appender.rolling.strategy.action.condition.nested_condition.type = IfAccumulatedFileSize
 appender.rolling.strategy.action.condition.nested_condition.exceeds = 2GB
+################################################
+######## Server -  old style pattern ###########
+appender.rolling_old.type = RollingFile
+appender.rolling_old.name = rolling_old
+appender.rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log
+appender.rolling_old.layout.type = PatternLayout
+appender.rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
+
+appender.rolling_old.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz
+appender.rolling_old.policies.type = Policies
+appender.rolling_old.policies.time.type = TimeBasedTriggeringPolicy
+appender.rolling_old.policies.time.interval = 1
+appender.rolling_old.policies.time.modulate = true
+appender.rolling_old.policies.size.type = SizeBasedTriggeringPolicy
+appender.rolling_old.policies.size.size = 128MB
+appender.rolling_old.strategy.type = DefaultRolloverStrategy
+appender.rolling_old.strategy.fileIndex = nomax
+appender.rolling_old.strategy.action.type = Delete
+appender.rolling_old.strategy.action.basepath = ${sys:es.logs.base_path}
+appender.rolling_old.strategy.action.condition.type = IfFileName
+appender.rolling_old.strategy.action.condition.glob = ${sys:es.logs.cluster_name}-*
+appender.rolling_old.strategy.action.condition.nested_condition.type = IfAccumulatedFileSize
+appender.rolling_old.strategy.action.condition.nested_condition.exceeds = 2GB
+################################################
 
 rootLogger.level = info
 rootLogger.appenderRef.console.ref = console
 rootLogger.appenderRef.rolling.ref = rolling
+rootLogger.appenderRef.rolling_old.ref = rolling_old
 
+######## Deprecation JSON #######################
 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.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.log.gz
+appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.json
+appender.deprecation_rolling.layout.type = ESJsonLayout
+appender.deprecation_rolling.layout.type_name = deprecation
+
+appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.json.gz
 appender.deprecation_rolling.policies.type = Policies
 appender.deprecation_rolling.policies.size.type = SizeBasedTriggeringPolicy
 appender.deprecation_rolling.policies.size.size = 1GB
 appender.deprecation_rolling.strategy.type = DefaultRolloverStrategy
 appender.deprecation_rolling.strategy.max = 4
+#################################################
+######## Deprecation -  old style pattern #######
+appender.deprecation_rolling_old.type = RollingFile
+appender.deprecation_rolling_old.name = deprecation_rolling_old
+appender.deprecation_rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log
+appender.deprecation_rolling_old.layout.type = PatternLayout
+appender.deprecation_rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
 
+appender.deprecation_rolling_old.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
+  _deprecation-%i.log.gz
+appender.deprecation_rolling_old.policies.type = Policies
+appender.deprecation_rolling_old.policies.size.type = SizeBasedTriggeringPolicy
+appender.deprecation_rolling_old.policies.size.size = 1GB
+appender.deprecation_rolling_old.strategy.type = DefaultRolloverStrategy
+appender.deprecation_rolling_old.strategy.max = 4
+#################################################
 logger.deprecation.name = org.elasticsearch.deprecation
 logger.deprecation.level = warn
 logger.deprecation.appenderRef.deprecation_rolling.ref = deprecation_rolling
+logger.deprecation.appenderRef.deprecation_rolling_old.ref = deprecation_rolling_old
 logger.deprecation.additivity = false
 
+######## Search slowlog JSON ####################
 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.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.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
+  .cluster_name}_index_search_slowlog.json
+appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
+appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
+
+appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
+  .cluster_name}_index_search_slowlog-%i.json.gz
 appender.index_search_slowlog_rolling.policies.type = Policies
 appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy
 appender.index_search_slowlog_rolling.policies.size.size = 1GB
 appender.index_search_slowlog_rolling.strategy.type = DefaultRolloverStrategy
 appender.index_search_slowlog_rolling.strategy.max = 4
+#################################################
+######## Search slowlog -  old style pattern ####
+appender.index_search_slowlog_rolling_old.type = RollingFile
+appender.index_search_slowlog_rolling_old.name = index_search_slowlog_rolling_old
+appender.index_search_slowlog_rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
+  _index_search_slowlog.log
+appender.index_search_slowlog_rolling_old.layout.type = PatternLayout
+appender.index_search_slowlog_rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
 
+appender.index_search_slowlog_rolling_old.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_old.policies.type = Policies
+appender.index_search_slowlog_rolling_old.policies.size.type = SizeBasedTriggeringPolicy
+appender.index_search_slowlog_rolling_old.policies.size.size = 1GB
+appender.index_search_slowlog_rolling_old.strategy.type = DefaultRolloverStrategy
+appender.index_search_slowlog_rolling_old.strategy.max = 4
+#################################################
 logger.index_search_slowlog_rolling.name = index.search.slowlog
 logger.index_search_slowlog_rolling.level = trace
 logger.index_search_slowlog_rolling.appenderRef.index_search_slowlog_rolling.ref = index_search_slowlog_rolling
+logger.index_search_slowlog_rolling.appenderRef.index_search_slowlog_rolling_old.ref = index_search_slowlog_rolling_old
 logger.index_search_slowlog_rolling.additivity = false
 
+######## Indexing slowlog JSON ##################
 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.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.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
+  _index_indexing_slowlog.json
+appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
+appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
+
+appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
+  _index_indexing_slowlog-%i.json.gz
 appender.index_indexing_slowlog_rolling.policies.type = Policies
 appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy
 appender.index_indexing_slowlog_rolling.policies.size.size = 1GB
 appender.index_indexing_slowlog_rolling.strategy.type = DefaultRolloverStrategy
 appender.index_indexing_slowlog_rolling.strategy.max = 4
+#################################################
+######## Indexing slowlog -  old style pattern ##
+appender.index_indexing_slowlog_rolling_old.type = RollingFile
+appender.index_indexing_slowlog_rolling_old.name = index_indexing_slowlog_rolling_old
+appender.index_indexing_slowlog_rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
+  _index_indexing_slowlog.log
+appender.index_indexing_slowlog_rolling_old.layout.type = PatternLayout
+appender.index_indexing_slowlog_rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
+
+appender.index_indexing_slowlog_rolling_old.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_old.policies.type = Policies
+appender.index_indexing_slowlog_rolling_old.policies.size.type = SizeBasedTriggeringPolicy
+appender.index_indexing_slowlog_rolling_old.policies.size.size = 1GB
+appender.index_indexing_slowlog_rolling_old.strategy.type = DefaultRolloverStrategy
+appender.index_indexing_slowlog_rolling_old.strategy.max = 4
+#################################################
 
 logger.index_indexing_slowlog.name = index.indexing.slowlog.index
 logger.index_indexing_slowlog.level = trace
 logger.index_indexing_slowlog.appenderRef.index_indexing_slowlog_rolling.ref = index_indexing_slowlog_rolling
+logger.index_indexing_slowlog.appenderRef.index_indexing_slowlog_rolling_old.ref = index_indexing_slowlog_rolling_old
 logger.index_indexing_slowlog.additivity = false

docs/reference/migration/migrate_7_0.asciidoc

@@ -25,6 +25,7 @@ See also <<release-highlights>> and <<es-release-notes>>.
 * <<breaking_70_snapshotstats_changes>>
 * <<breaking_70_restclient_changes>>
 * <<breaking_70_low_level_restclient_changes>>
+* <<breaking_70_logging_changes>>
 
 [float]
 === Indices created before 7.0
@@ -58,3 +59,4 @@ include::migrate_7_0/scripting.asciidoc[]
 include::migrate_7_0/snapshotstats.asciidoc[]
 include::migrate_7_0/restclient.asciidoc[]
 include::migrate_7_0/low_level_restclient.asciidoc[]
+include::migrate_7_0/logging.asciidoc[]

docs/reference/migration/migrate_7_0/logging.asciidoc

@@ -0,0 +1,33 @@
+[float]
+[[breaking_70_logging_changes]]
+=== Logging changes
+
+[float]
+==== New JSON format log files in `log` directory
+
+Elasticsearch now will produce additional log files in JSON format. They will be stored in `*.json` suffix files.
+Following files should be expected now in log directory:
+* ${cluster_name}_server.json
+* ${cluster_name}_deprecation.json
+* ${cluster_name}_index_search_slowlog.json
+* ${cluster_name}_index_indexing_slowlog.json
+* ${cluster_name}.log
+* ${cluster_name}_deprecation.log
+* ${cluster_name}_index_search_slowlog.log
+* ${cluster_name}_index_indexing_slowlog.log
+* ${cluster_name}_audit.json
+* gc.log
+
+Note: You can configure which of these files are written by editing `log4j2.properties`.
+
+[float]
+==== Log files ending with `*.log` deprecated
+Log files with the `.log` file extension using the old pattern layout format
+are now considered deprecated and the newly added JSON log file format with
+the `.json` file extension should be used instead.
+Note: GC logs which are written to the file `gc.log` will not be changed.
+
+[float]
+==== Docker output in JSON format
+
+All Docker console logs are now in JSON format. You can distinguish logs streams with the `type` field.