Provide substitution for elasticsearch.logQueries in the new logging config

[mshustov]

With the new logging config, we can deprecate logging.logQueries and provide logging configuration that can be used instead. The current setup for logQueries outputs logs for both data and admin clients. While in the new platform both loggers are created with elasticsearch as a parent context, therefore users have to declare config rules for both contexts separately.

logging:
  loggers:
    - context: elasticsearch.data
      appenders: [console]
      level: debug

I'd suggest introducing a common context for both loggers to simplify setup: elasticsearch.client.{client_name} it also would help us when we expose a single elasticsearch client #49870
UPDATED 04.08: there is no separate admin client anymore.

[elasticmachine]

Pinging @elastic/kibana-platform (Team:Platform)

[tylersmalley]

I am surprised we kept the admin and data cluster concepts in the new platform as it's a fragment leftover from the Tribe days. Are we still separating reads and writes with these?

[joshdover]

No they're both the same at this point and can be used interchangeably. We decided in #49870 to just not remove this until we introduce the new Elasticsearch client.

[joshdover]

Been digging into this a bit and there's a few things that warrant some discussion.

First, the goal of this task is to have a config that allows a user to enable elasticsearch query logging, but is disabled by default (on 7.x branch). Since this feature already exists in the current elasticsearch.logQueries form, this task is about creating a config that is compatible with Core's new logger configuration, which will be the only option in 8.0.

Where I'm struggling is to find a way to support both elasticsearch.logQueries and a config like all in the same branch:

logging:
  loggers:
    - context: elasticsearch.queries
      level: info

Options

(1) The "obvious" way to me it could be done is to remove the checks in Core for elasticsearch.logQueries and always creating the log records, but then do filtering on the LegacyLoggerAppender side based on the logQueries config. The main issue is that the appenders are constructed dynamically by the LoggingSystem, so the LoggingSystem would need to have access to the Elasticsearch service's config 👎

(2) The best alternative I can find is to leverage the logging.configure API from with the Elasticsearch service to dynamically lower the level for the elasticsearch.query logging context to debug when elasticsearch.logQueries is set to true. The primary downsides I see to this is that when the legacy setting, logging.verbose=true, ES queries will be logged even if elasticsearch.logQueries is false. This is different behavior than what we have now, but I would argue that it's more in line with what users may expect from verbose logging.

(3) An alternative would be to determine whether or not we're using the LegacyLoggingAppender from within the Elasticsearch code and then only create query log records when we're using the legacy appender AND logQueries is true. This isn't very clean either since it requires the LoggingSystem to expose whether or not we're using the legacy appended (and which context is using it). We'd also have to add some reactive code since the logging configuration can change at runtime, something we don't have in place right now for ES config. 👎

(4) An easier alternative is to do nothing in 7.x at all and leave the existing code as-is. We can then make this change in master/8.0 only to remove elasticsearch.logQueries and just produce these log messages with regular verbosity configuration as all other logs. This is a fairly small change, so if we're concerned about the divergence between master and 7.x, we should be ok to hold off until the 7.15 timeframe to make this change.

At this point, I lean towards (2) but would be ok with (4) as well. Both (1) and (3) seem to add more complexity we'd just have to remove later in 8.0.

@restrry @lukeelmers @TinaHeiligers thoughts?

[mshustov]

with the Elasticsearch service to dynamically lower the level for the elasticsearch.query logging context to debug when elasticsearch.logQueries is set to true

All queries already logged with debug level. Although we might consider lowering the failed request logs to the debug level as well.
the new client:

kibana/src/core/server/elasticsearch/client/configure_client.ts

Lines 73 to 79 in 170a295

	if (error) {
	logger.error(getErrorMessage(error, event));
	} else {
	logger.debug(getResponseMessage(event), {
	tags: ['query'],
	});
	}

the legacy client:

kibana/src/core/server/elasticsearch/legacy/elasticsearch_client_config.ts

Line 201 in 170a295

log.debug(`${statusCode}\n${method} ${options.path}\n${query ? query.trim() : ''}`, {

The primary downsides I see to this is that when the legacy setting, logging.verbose=true, ES queries will be logged even if elasticsearch.logQueries is false

Is that the same as removing this condition ?

kibana/src/core/server/elasticsearch/client/configure_client.ts

Line 72 in 170a295

if (event && logQueries) {

If so, I'm okay to remove the logQueries configuration setting and log a deprecation message when an end-user sets it in the config file. In this way, we will start encouraging users to use the new configuration today.

[pgayvallet]

ES queries will be logged even if elasticsearch.logQueries is false. This is different behavior than what we have now, but I would argue that it's more in line with what users may expect from verbose logging.

This seems fine to me. TBH I always wondered why I needed to set both to get what I want when debugging.

All queries already logged with debug level. Although we might consider lowering the failed request logs to the debug level as well.

Seems ok. These are not even uncatched errors, so the error level was probably overkill in the first place.

At this point, I lean towards (2) but would be ok with (4) as well

We are starting to reach a point in time where we should decide on precise guidelines about how to should choose master/7.x divergence (4) versus compromise (2) in such scenarios imho.

If I had to choose, I'll go with (4). But I'm totally fine with (2) which seems like the best option if we don't want to introduce divergence.

[mshustov]

If I had to choose, I'll go with (4). But I'm totally fine with (2) which seems like the best option if we don't want to introduce divergence.

My concern with (4) is not divergence but lack of real-world testing before the v8.0 release.

[lukeelmers]

dynamically lower the level for the elasticsearch.query logging context to debug when elasticsearch.logQueries is set to true

Is there a particular reason why we need to log the "new" elasticsearch.queries logs at an info level instead of debug?

If we logged at a debug level, it would simplify things as we wouldn't have the added complexity of dynamically reconfiguring logging from the elasticsearch service. Instead we could take an "opt-in" approach where folks can see the new logs in verbose mode, or when explicitly enabling debug logs for elasticsearch.queries context.

The main downside to this approach is duplicate log entries, however as @restrry points out this would serve to encourage folks to start using the new config.

FWIW, this is basically the same approach we took (so far) in response logs and ops logs. So if we were to do anything differently here, we may want to reconsider our approach in those PRs too.

[pgayvallet]

Is there a particular reason why we need to log the "new" elasticsearch.queries logs at an info level instead of debug?

We will be logging at the debug level. The problem here is to have the current elasticsearch.logQueries option still works with the new implementation. This is why one option would be to change the elasticsearch.queries logger's level from INFO to DEBUG when elasticsearch.logQueries=true.

FWIW, this is basically the same approach we took (so far) in response logs and ops logs.
The main downside to this approach is duplicate log entries

Main difference is that for res/ops logs, the legacy implementation was directly using the legacy logging system, and the new implementation is using the new logging system (and that these are two distinct implementations / code outputting the logs).

That's not the case for the ES (and legacy ES) clients, that are already using the new logging system (which redirects to the legacy appender atm). We don't have the duplicated logs issues here, but we need to support the legacy/deprecated way to enable ES query logging.

[joshdover]

Thanks all for the responses! Here's my replies + summary:

In response to @restrry:

All queries already logged with debug level. Although we might consider lowering the failed request logs to the debug level as well.

👍

Is that the same as removing this condition ?

kibana/src/core/server/elasticsearch/client/configure_client.ts

Line 72 in 170a295

if (event && logQueries) {

Yes, that's essentially it. Initially I was thinking we would also need to dynamically set the logging context level config based on elasticsearch.logQueries. The reason for doing this dynamically in 7.x would be to maintain compatibility with the currently documented configuration. However, I don't think this is necessary because as it is today, you have to set both elasticsearch.logQueries and logging.verbose to get query logs. Now, users will be able to just set logging.verbose and get everything.

---

In response to @lukeelmers:

Is there a particular reason why we need to log the "new" elasticsearch.queries logs at an info level instead of debug?

If we logged at a debug level, it would simplify things as we wouldn't have the added complexity of dynamically reconfiguring logging from the elasticsearch service. Instead we could take an "opt-in" approach where folks can see the new logs in verbose mode, or when explicitly enabling debug logs for elasticsearch.queries context.

No, the idea with (2) was that we would always be logging these LogRecords at the debug level but would dynamically lower the configuration filter on the elasticsearch.query context when elasticsearch.logQueries=true. This would be the equivalent of setting this in the yaml:

logging:
  loggers:
    - context: elasticsearch.query
      level: debug

But as I mentioned above, I don't think we need to do this at all since you previously had to set logging.verbose anyways.

---

In response to @pgayvallet:

Main difference is that for res/ops logs, the legacy implementation was directly using the legacy logging system, and the new implementation is using the new logging system (and that these are two distinct implementations / code outputting the logs).

That's not the case for the ES (and legacy ES) clients, that are already using the new logging system (which redirects to the legacy appender atm). We don't have the duplicated logs issues here, but we need to support the legacy/deprecated way to enable ES query logging.

Yep that's exactly right. We won't have any duplicated logs in this case, but since the log messages are being produced on the new logging system, we just want to make sure we don't break the old configuration method.

---

So in conclusion, this solution now is to:

• Remove the usage of elasticsearch.logQueries completely + add an unused config deprecation warning
• Downgraded/change the logging level of ES query errors to debug
• Create a follow up PR to remove elasticsearch.logQueries from the master/8.0 branch

The only caveat with this option is that starting in 7.12, turning on logging.verbose will now include Elasticsearch query logs, which it did not before. This will not break any existing config, but will make the verbose logs, well a bit more verbose 😄

[lukeelmers]

Main difference is that for res/ops logs, the legacy implementation was directly using the legacy logging system, and the new implementation is using the new logging system

Ah, thanks for clarifying. That was the key point I was overlooking. In that case Josh's solution proposed above makes sense to me 👍

[mshustov]

This will not break any existing config, but will make the verbose logs, well a bit more verbose 😄

nothing even comes close to taskManager spamming in verbose mode :D