Log all index settings updates at INFO level

[DaveCTurner]

Most updates to index settings are handled by a settings update consumer registered via IndexScopedSettings#addSettingsUpdateConsumer. In contrast, the settings defined in IndexMetaData (index.blocks.*, index.priority, etc.) are consumed directly from the Settings object instead. Changes to index settings that are consumed via a settings update consumer result in an INFO-level log message (see e.g. #49969). Changes to directly-consumed settings do not automatically result in any log messages, and we explicitly handle some special cases like index.number_of_replicas elsewhere.

I think this is confusing since from a user's perspective there's no way to distinguish these two classes of index settings. A user seeing that some settings updates are logged may wrongly infer that the lack of logging of other settings updates means that those other settings were not updated.

Should we make this consistent? Consistency is good, but noisier logs are bad.

[elasticmachine]

Pinging @elastic/es-core-infra (:Core/Infra/Settings)

[DaveCTurner]

For example, in 7.6.0 the following commands ...

# create a test index
PUT /i
{}

# update its settings
PUT /i/_settings
{
  "index.priority": 42,
  "index.number_of_replicas": 0,
  "index.refresh_interval": "60s"
}

... yield the following logs ...

[2020-04-08T18:26:40,087][INFO ][o.e.c.m.MetaDataCreateIndexService] [node-0] [i] creating index, cause [api], templates [], shards [1]/[1], mappings []
[2020-04-08T18:26:55,678][INFO ][o.e.c.m.MetaDataUpdateSettingsService] [node-0] updating number_of_replicas to [0] for indices [i]
[2020-04-08T18:26:55,685][INFO ][o.e.c.s.IndexScopedSettings] [node-0] [i] updating [index.refresh_interval] from [1s] to [60s]
[2020-04-08T18:26:55,730][INFO ][o.e.c.s.IndexScopedSettings] [node-0] [i] updating [index.refresh_interval] from [1s] to [60s]

• We do not log the change to index.priority at all.
• We do log the change to index.number_of_replicas but this is a special case.
• We do log the change to index.refresh_interval since, like most dynamic index settings, this update is consumed by a consumer registered with IndexScopedSettings#addSettingsUpdateConsumer.

[DaveCTurner]

We discussed this today and agreed that consistency is good, and therefore we should log all index settings updates. We also discussed whether we should demote these to DEBUG level, but concluded that we would prefer to keep them all at INFO.

[hubbleview]

++ Log index setting updates at INFO level.

Here is one scenario that such logging would be helpful for troubleshooting.

• Flood stage watermark was hit on one node, log mentioned all indices on this node will be marked read-only.
• And, we also saw logs like below:

org.elasticsearch.cluster.block.ClusterBlockException: index [INDEX_NAME] blocked by: [TOO_MANY_REQUESTS/12/disk usage exceeded flood-stage watermark, index has read-only-allow-delete block];

• However, free disk space still kept decreasing till file system full and node fully dead.
• When checking file system usage details after node was down, all space were used by index shard directories, so it's not about logs or other things in that file system.
• Without logs of index setting updates, we couldn't tell if the index setting read-only-allow-delete was modified or not.

[DaveCTurner]

we couldn't tell if the index setting read-only-allow-delete was modified or not.

If the master logged all indices on this node will be marked read-only and there were other logs indicating index has read-only-allow-delete block then you can be confident that the read-only-allow-delete was indeed modified.

[hubbleview]

If the master logged all indices on this node will be marked read-only and there were other logs indicating index has read-only-allow-delete block then you can be confident that the read-only-allow-delete was indeed modified.

• Yes, I believe master node has flagged all indices on this node as read-only.
• I was thinking a possibility that index setting was updated by API from external, which I hoped to find in the logs.
• Even we see index has read-only-allow-delete block for particular index, we can't tell if that block setting of other indices have been updated and still being written.