mirror of
https://github.com/honeymoose/OpenSearch.git
synced 2025-02-05 20:48:22 +00:00
First, some background: we have 15 different methods to get a logger in Elasticsearch but they can be broken down into three broad categories based on what information is provided when building the logger. Just a class like: ``` private static final Logger logger = ESLoggerFactory.getLogger(ActionModule.class); ``` or: ``` protected final Logger logger = Loggers.getLogger(getClass()); ``` The class and settings: ``` this.logger = Loggers.getLogger(getClass(), settings); ``` Or more information like: ``` Loggers.getLogger("index.store.deletes", settings, shardId) ``` The goal of the "class and settings" variant is to attach the node name to the logger. Because we don't always have the settings available, we often use the "just a class" variant and get loggers without node names attached. There isn't any real consistency here. Some loggers get the node name because it is convenient and some do not. This change makes the node name available to all loggers all the time. Almost. There are some caveats are testing that I'll get to. But in *production* code the node name is node available to all loggers. This means we can stop using the "class and settings" variants to fetch loggers which was the real goal here, but a pleasant side effect is that the ndoe name is now consitent on every log line and optional by editing the logging pattern. This is all powered by setting the node name statically on a logging formatter very early in initialization. Now to tests: tests can't set the node name statically because subclasses of `ESIntegTestCase` run many nodes in the same jvm, even in the same class loader. Also, lots of tests don't run with a real node so they don't *have* a node name at all. To support multiple nodes in the same JVM tests suss out the node name from the thread name which works surprisingly well and easy to test in a nice way. For those threads that are not part of an `ESIntegTestCase` node we stick whatever useful information we can get form the thread name in the place of the node name. This allows us to keep the logger format consistent.
119 lines
5.7 KiB
Plaintext
119 lines
5.7 KiB
Plaintext
[[index-modules-slowlog]]
|
|
== Slow Log
|
|
|
|
[float]
|
|
[[search-slow-log]]
|
|
=== Search Slow Log
|
|
|
|
Shard level slow search log allows to log slow search (query and fetch
|
|
phases) into a dedicated log file.
|
|
|
|
Thresholds can be set for both the query phase of the execution, and
|
|
fetch phase, here is a sample:
|
|
|
|
[source,yaml]
|
|
--------------------------------------------------
|
|
index.search.slowlog.threshold.query.warn: 10s
|
|
index.search.slowlog.threshold.query.info: 5s
|
|
index.search.slowlog.threshold.query.debug: 2s
|
|
index.search.slowlog.threshold.query.trace: 500ms
|
|
|
|
index.search.slowlog.threshold.fetch.warn: 1s
|
|
index.search.slowlog.threshold.fetch.info: 800ms
|
|
index.search.slowlog.threshold.fetch.debug: 500ms
|
|
index.search.slowlog.threshold.fetch.trace: 200ms
|
|
|
|
index.search.slowlog.level: info
|
|
--------------------------------------------------
|
|
|
|
All of the above settings are _dynamic_ and are set per-index.
|
|
|
|
By default, none are enabled (set to `-1`). Levels (`warn`, `info`,
|
|
`debug`, `trace`) allow to control under which logging level the log
|
|
will be logged. Not all are required to be configured (for example, only
|
|
`warn` threshold can be set). The benefit of several levels is the
|
|
ability to quickly "grep" for specific thresholds breached.
|
|
|
|
The logging is done on the shard level scope, meaning the execution of a
|
|
search request within a specific shard. It does not encompass the whole
|
|
search request, which can be broadcast to several shards in order to
|
|
execute. Some of the benefits of shard level logging is the association
|
|
of the actual execution on the specific machine, compared with request
|
|
level.
|
|
|
|
The logging file is configured by default using the following
|
|
configuration (found in `log4j2.properties`):
|
|
|
|
[source,properties]
|
|
--------------------------------------------------
|
|
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.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
|
|
|
|
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
|
|
--------------------------------------------------
|
|
|
|
[float]
|
|
[[index-slow-log]]
|
|
=== Index Slow log
|
|
|
|
The indexing slow log, similar in functionality to the search slow
|
|
log. The log file name ends with `_index_indexing_slowlog.log`. Log and
|
|
the thresholds are configured in the same way as the search slowlog.
|
|
Index slowlog sample:
|
|
|
|
[source,yaml]
|
|
--------------------------------------------------
|
|
index.indexing.slowlog.threshold.index.warn: 10s
|
|
index.indexing.slowlog.threshold.index.info: 5s
|
|
index.indexing.slowlog.threshold.index.debug: 2s
|
|
index.indexing.slowlog.threshold.index.trace: 500ms
|
|
index.indexing.slowlog.level: info
|
|
index.indexing.slowlog.source: 1000
|
|
--------------------------------------------------
|
|
|
|
All of the above settings are _dynamic_ and are set per-index.
|
|
|
|
By default Elasticsearch will log the first 1000 characters of the _source in
|
|
the slowlog. You can change that with `index.indexing.slowlog.source`. Setting
|
|
it to `false` or `0` will skip logging the source entirely an setting it to
|
|
`true` will log the entire source regardless of size. The original `_source` is
|
|
reformatted by default to make sure that it fits on a single log line. If preserving
|
|
the original document format is important, you can turn off reformatting by setting
|
|
`index.indexing.slowlog.reformat` to `false`, which will cause the source to be
|
|
logged "as is" and can potentially span multiple log lines.
|
|
|
|
The index slow log file is configured by default in the `log4j2.properties`
|
|
file:
|
|
|
|
[source,properties]
|
|
--------------------------------------------------
|
|
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.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
|
|
|
|
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
|
|
--------------------------------------------------
|