Watcher: Metadata inconsistencies lead to watcher errors

[tomcallahan]

We received the below stack trace from a user running 5.6.8, but we believe the issue is just as applicable on latest.

The crux of the issue is the dynamically-mapped metadata field inside of watch definitions. Each watch may define the metadata field as it please, however this must all converge to a single schema in the watch history index. In the example below, the customer has many watches, all of which have an integer or floating point value for the redacted_field_1 in the stack trace below. When the daily watcher history index is created, two of those watches may fire at the same time, yielding the stack trace below. This seems to be a fundamental issue with how the history index works.

[2018-05-06T00:00:03,053][DEBUG][o.e.a.a.i.m.p.TransportPutMappingAction] [es5mon002A] failed to put mappings on indices [[[.watcher-history-6-2018.05.06/fPJxLD3rTWuODopoXYD1bA]]], type [doc] 
java.lang.IllegalArgumentException: mapper [metadata.redacted_field_1] cannot be changed from type [float] to [long] 
at org.elasticsearch.index.mapper.MappedFieldType.checkTypeName(MappedFieldType.java:151) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MappedFieldType.checkCompatibility(MappedFieldType.java:163) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.FieldTypeLookup.checkCompatibility(FieldTypeLookup.java:128) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.FieldTypeLookup.copyAndAddAll(FieldTypeLookup.java:94) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.internalMerge(MapperService.java:400) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.internalMerge(MapperService.java:336) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.merge(MapperService.java:268) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.metadata.MetaDataMappingService$PutMappingExecutor.applyRequest(MetaDataMappingService.java:311) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.metadata.MetaDataMappingService$PutMappingExecutor.execute(MetaDataMappingService.java:230) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.executeTasks(ClusterService.java:634) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.calculateTaskOutputs(ClusterService.java:612) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.runTasks(ClusterService.java:571) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService$ClusterServiceTaskBatcher.run(ClusterService.java:263) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:150) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:188) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:575) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:247) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:210) [elasticsearch-5.6.8.jar:5.6.8] 
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_151] 
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_151] 
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151] 
[2018-05-06T00:00:03,076][ERROR][o.e.x.w.e.ExecutionService] [es5mon002A] failed to update watch record [REDACTED] 
java.lang.IllegalArgumentException: mapper [metadata.redacted_field_1] cannot be changed from type [float] to [long] 
at org.elasticsearch.index.mapper.MappedFieldType.checkTypeName(MappedFieldType.java:151) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MappedFieldType.checkCompatibility(MappedFieldType.java:163) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.FieldTypeLookup.checkCompatibility(FieldTypeLookup.java:128) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.FieldTypeLookup.copyAndAddAll(FieldTypeLookup.java:94) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.internalMerge(MapperService.java:400) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.internalMerge(MapperService.java:336) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.merge(MapperService.java:268) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.metadata.MetaDataMappingService$PutMappingExecutor.applyRequest(MetaDataMappingService.java:311) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.metadata.MetaDataMappingService$PutMappingExecutor.execute(MetaDataMappingService.java:230) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.executeTasks(ClusterService.java:634) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.calculateTaskOutputs(ClusterService.java:612) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.runTasks(ClusterService.java:571) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService$ClusterServiceTaskBatcher.run(ClusterService.java:263) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:150) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:188) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:575) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:247) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:210) ~[elasticsearch-5.6.8.jar:5.6.8] 
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_151] 
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_151] 
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151] 
2018-05-06T00:00:03,074][ERROR][o.e.x.w.e.ExecutionService] [es5mon002A] failed to update watch record [REDACTED] 
java.lang.IllegalArgumentException: mapper [metadata.redacted_field_1] cannot be changed from type [float] to [long] 
at org.elasticsearch.index.mapper.MappedFieldType.checkTypeName(MappedFieldType.java:151) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MappedFieldType.checkCompatibility(MappedFieldType.java:163) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.FieldTypeLookup.checkCompatibility(FieldTypeLookup.java:128) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.FieldTypeLookup.copyAndAddAll(FieldTypeLookup.java:94) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.internalMerge(MapperService.java:400) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.internalMerge(MapperService.java:336) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.index.mapper.MapperService.merge(MapperService.java:268) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.metadata.MetaDataMappingService$PutMappingExecutor.applyRequest(MetaDataMappingService.java:311) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.metadata.MetaDataMappingService$PutMappingExecutor.execute(MetaDataMappingService.java:230) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.executeTasks(ClusterService.java:634) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.calculateTaskOutputs(ClusterService.java:612) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService.runTasks(ClusterService.java:571) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.ClusterService$ClusterServiceTaskBatcher.run(ClusterService.java:263) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:150) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:188) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:575) [elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:247) ~[elasticsearch-5.6.8.jar:5.6.8] 
at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:210) ~[elasticsearch-5.6.8.jar:5.6.8] 
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_151] 
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_151] 
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151] 

[elasticmachine]

Pinging @elastic/es-core-infra

[spinscale]

The issue is not affects the watch history indices, but also affects the .watches index.

See https://github.com/elastic/elasticsearch/blob/master/x-pack/plugin/core/src/main/resources/watches.json#L55-L58 and https://github.com/elastic/elasticsearch/blob/master/x-pack/plugin/core/src/main/resources/watch-history.json#L596-L599

We should not make this searchable to avoid such conflicts. We also cannot just convert everything to a string, as this still would pose problems if one field is an object in a watch, but is not in another.

[spinscale]

As a workaround for the watch history a user could retrieve the current template, and change the following for the metadata field to

PUT _template/.watch-history-7
  ... ALL THE OTHER TEMPLATE THINGS ...
        "metadata": {
          "type": "object",
          "enabled": false,
          "dynamic": true
        }
  ... ALL THE OTHER TEMPLATE THINGS ...

[dakrone]

This has been open for quite a while, and hasn't had a lot of interest. For now I'm going to close this as something we aren't planning on implementing. We can re-open it later if needed.