DateFieldMapper throws mapper_parser_exception even if ignore_malformed is set

[lindstromhenrik]

Elasticsearch version (bin/elasticsearch --version): 7.5.0 (official docker image)

Plugins installed: none

JVM version (java -version): N/A using docker image

OS version (uname -a if on a Unix-like system): N/A using docker image

Description of the problem including expected versus actual behavior:
DateFieldMapper throws mapper_parser_exception even if ignore_malformed is set.

Note: 7.4.0 works as expected.

Steps to reproduce:

1. docker run --name elasticsearch -p 9200:9200 -p 9300:9300 -e "discovery.type=single-node" elasticsearch:7.5.0
2. PUT localhost:9200/my_index

{
  "mappings": {
    "properties": {
      "date": {
        "type": "date",
        "ignore_malformed": true
      }
    }
  }
}

3. PUT localhost:9200/my_index/_doc/1

{
	"date": -2147483648
}

Response:

{
    "error": {
        "root_cause": [
            {
                "type": "mapper_parsing_exception",
                "reason": "failed to parse field [date] of type [date] in document with id '1'. Preview of field's value: '-2147483648'"
            }
        ],
        "type": "mapper_parsing_exception",
        "reason": "failed to parse field [date] of type [date] in document with id '1'. Preview of field's value: '-2147483648'",
        "caused_by": {
            "type": "date_time_exception",
            "reason": "Invalid value for Year (valid values -999999999 - 999999999): -2147483648"
        }
    },
    "status": 400
}

Provide logs (if relevant):
{"type": "server", "timestamp": "2019-12-11T15:12:23,713Z", "level": "DEBUG", "component": "o.e.a.b.TransportShardBulkAction", "cluster.name": "docker-cluster", "node.name": "443a077db5fd", "message": "[my_index][0] failed to execute bulk item (index) index {[my_index][_doc][1], source[{\n\t"date": -2147483648\n}]}", "cluster.uuid": "gDdt0k7RRCSTmKLW_NCaLg", "node.id": "j_4QzFLNTMepgleFh0l2mA" ,
"stacktrace": ["org.elasticsearch.index.mapper.MapperParsingException: failed to parse field [date] of type [date] in document with id '1'. Preview of field's value: '-2147483648'",
"at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:299) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrField(DocumentParser.java:488) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentParser.parseValue(DocumentParser.java:614) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentParser.innerParseObject(DocumentParser.java:427) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrNested(DocumentParser.java:395) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentParser.internalParseDocument(DocumentParser.java:112) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentParser.parseDocument(DocumentParser.java:71) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:267) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:776) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShard.applyIndexOperation(IndexShard.java:753) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShard.applyIndexOperationOnPrimary(IndexShard.java:725) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.bulk.TransportShardBulkAction.executeBulkItemRequest(TransportShardBulkAction.java:258) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:161) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:193) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:118) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:79) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryShardReference.perform(TransportReplicationAction.java:917) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.ReplicationOperation.execute(ReplicationOperation.java:108) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.runWithPrimaryShardReference(TransportReplicationAction.java:394) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.lambda$doRun$0(TransportReplicationAction.java:316) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShard.lambda$wrapPrimaryOperationPermitListener$21(IndexShard.java:2752) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.ActionListener$3.onResponse(ActionListener.java:113) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShardOperationPermits.acquire(IndexShardOperationPermits.java:285) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShardOperationPermits.acquire(IndexShardOperationPermits.java:237) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.shard.IndexShard.acquirePrimaryOperationPermit(IndexShard.java:2726) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.TransportReplicationAction.acquirePrimaryOperationPermit(TransportReplicationAction.java:858) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.doRun(TransportReplicationAction.java:312) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.action.support.replication.TransportReplicationAction.handlePrimaryRequest(TransportReplicationAction.java:275) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler$1.doRun(SecurityServerTransportInterceptor.java:257) [x-pack-security-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler.messageReceived(SecurityServerTransportInterceptor.java:315) [x-pack-security-7.5.0.jar:7.5.0]",
"at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:63) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:752) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:773) [elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.5.0.jar:7.5.0]",
"at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]",
"at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]",
"at java.lang.Thread.run(Thread.java:830) [?:?]",
"Caused by: java.time.DateTimeException: Invalid value for Year (valid values -999999999 - 999999999): -2147483648",
"at java.time.temporal.TemporalAccessor.get(TemporalAccessor.java:224) ~[?:?]",
"at org.elasticsearch.common.time.DateFormatters.getYear(DateFormatters.java:1933) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.time.DateFormatters.access$000(DateFormatters.java:55) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.time.DateFormatters$1.queryFrom(DateFormatters.java:1902) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.common.time.DateFormatters$1.queryFrom(DateFormatters.java:1896) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at java.time.format.Parsed.query(Parsed.java:235) ~[?:?]",
"at org.elasticsearch.common.time.DateFormatters.from(DateFormatters.java:1848) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DateFieldMapper$DateFieldType.parse(DateFieldMapper.java:331) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.DateFieldMapper.parseCreateField(DateFieldMapper.java:538) ~[elasticsearch-7.5.0.jar:7.5.0]",
"at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:277) ~[elasticsearch-7.5.0.jar:7.5.0]",
"... 40 more"] }

[elasticmachine]

Pinging @elastic/es-search (:Search/Mapping)

[cbuescher]

I can confirm, the example still works for me on 7.4.2 but not on 7.5.0

[cbuescher]

I think this is related to #46675 which made date parsing stricter in 7.5. We probably need to be prepared to catch more date parsing exceptions when ignore_malformed is set. Working on a fix...

[faxm0dem]

I'm not sure this is related, but when using ignore_malformed:false explicitly, it's not even possible to index valid dates:

7.5.1☠ HTTP PUT https://elastic:9200/syslog-2020.01.23/_mapping <<<'{"properties":{"time_explicit":{"ignore_malformed":false,"type":"date","format":"'"YYYY-MM-dd'T'HH:mm:ssZ"'"}}}'
HTTP/1.1 200 OK
content-length: 21
content-type: application/json; charset=UTF-8

{
    "acknowledged": true
}

7.5.1☠ HTTP PUT https://elastic:9200/syslog-2020.01.23/_mapping <<<'{"properties":{"time_implicit":{"type":"date","format":"'"YYYY-MM-dd'T'HH:mm:ssZ"'"}}}'
HTTP/1.1 200 OK
content-length: 21
content-type: application/json; charset=UTF-8

{
    "acknowledged": true
}

7.5.1☠ HTTP POST https://elastic:9200/syslog-2020.01.23/_doc <<<'{"time_explicit":"2020-01-23T08:46:31+01:00"}'
HTTP/1.1 400 Bad Request
content-length: 738
content-type: application/json; charset=UTF-8

{
    "error": {
        "caused_by": {
            "caused_by": {
                "reason": "date_time_parse_exception: Text '2020-01-23T08:46:31+01:00' could not be parsed at index 19",
                "type": "date_time_parse_exception"
            },
            "reason": "failed to parse date field [2020-01-23T08:46:31+01:00] with format [YYYY-MM-dd'T'HH:mm:ssZ]",
            "type": "illegal_argument_exception"
        },
        "reason": "failed to parse field [time_explicit] of type [date] in document with id '6eqs0W8Bq4GBZRSzFXdL'. Preview of field's value: '2020-01-23T08:46:31+01:00'",
        "root_cause": [
            {
                "reason": "failed to parse field [time_explicit] of type [date] in document with id '6eqs0W8Bq4GBZRSzFXdL'. Preview of field's value: '2020-01-23T08:46:31+01:00'",
                "type": "mapper_parsing_exception"
            }
        ],
        "type": "mapper_parsing_exception"
    },
    "status": 400
}

7.5.1☠ HTTP POST https://elastic:9200/syslog-2020.01.23/_doc <<<'{"time_implicit":"2020-01-23T08:46:31+01:00"}'
HTTP/1.1 201 Created
Location: /syslog-2020.01.23/_doc/6uqs0W8Bq4GBZRSzMXfn
content-length: 184
content-type: application/json; charset=UTF-8

{
    "_id": "6uqs0W8Bq4GBZRSzMXfn",
    "_index": "syslog-2020.01.23",
    "_primary_term": 1,
    "_seq_no": 0,
    "_shards": {
        "failed": 0,
        "successful": 2,
        "total": 2
    },
    "_type": "_doc",
    "_version": 1,
    "result": "created"
}