Designate created_at mapping parser exception

Bug #1579844 reported by Travis Tripp
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Designate
Fix Released
Critical
Graham Hayes
OpenStack Searchlight
Invalid
Critical
Steve McLellan

Bug Description

At some point shortly after mitaka the date format coming from designate's API changed so that it's no longer 8601 compliant. For instance:

  "updated_at": "2016-05-24 14:53:56"

This has caused us some

Graham suspects this is due to an oslo utils change.

Searchlight error:

Fresh devstack. Created designate records via CLI. Got the following in listener:

2016-05-09 11:40:38.451 ERROR searchlight.elasticsearch.plugins.base [-] (u'1 document(s) failed to index.', [{u'index': {u'status': 400, u'_type': u'OS::Designate::RecordSet', u'_id': u'2215fbf6-8421-444b-9201-ecd442c2a524', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-09 17:40:38], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-09 17:40:38" is malformed at " 17:40:38"]; ', u'_index': u'searchlight-2016_05_09_17_24_23'}}])

Did a bulk indexing and got the following:

2016-05-10 13:30:42.258 INFO elasticsearch [-] POST http://127.0.0.1:9200/searchlight-2016_05_10_19_30_41/OS%3A%3ADesignate%3A%3AZone/_bulk [status:200 request:0.004s]
2016-05-10 13:30:42.258 DEBUG elasticsearch [-] > {"index": {"_id": "f4132f97-d477-4e8c-8afd-2ad75838cfa4", "_version": "462817513000000000", "_version_type": "external"}}
{"status": "ACTIVE", "masters": [], "name": "demo.demo.", "transferred_at": null, "created_at": "2016-05-09 18:11:09", "__searchlight-user-role": ["user", "admin"], "pool_id": "794ccc2c-d751-44fe-b57f-8894c9f5c842", "updated_at": "2016-05-09 18:11:53", "version": 4, "id": "f4132f97-d477-4e8c-8afd-2ad75838cfa4", "ttl": 3600, "action": "NONE", "attributes": {}, "serial": 1462817493, "project_id": "4bade81378e6428db0e896db77d68e02", "type": "PRIMARY", "email": "<email address hidden>", "description": null}
{"index": {"_id": "bdcb0f05-5fe2-4d0d-a168-5103d147af5e", "_version": "462908630000000000", "_version_type": "external"}}
{"status": "ACTIVE", "masters": [], "name": "my.web.domain.", "transferred_at": null, "created_at": "2016-05-10 19:30:09", "__searchlight-user-role": ["user", "admin"], "pool_id": "794ccc2c-d751-44fe-b57f-8894c9f5c842", "updated_at": "2016-05-10 19:30:30", "version": 2, "id": "bdcb0f05-5fe2-4d0d-a168-5103d147af5e", "ttl": 50, "action": "NONE", "attributes": {}, "serial": 1462908609, "project_id": "4bade81378e6428db0e896db77d68e02", "type": "PRIMARY", "email": "<email address hidden>", "description": ""}
 from (pid=114287) log_request_success /usr/local/lib/python2.7/dist-packages/elasticsearch/connection/base.py:65
2016-05-10 13:30:42.259 DEBUG elasticsearch [-] < {"took":4,"errors":true,"items":[{"index":{"_index":"searchlight-2016_05_10_19_30_41","_type":"OS::Designate::Zone","_id":"f4132f97-d477-4e8c-8afd-2ad75838cfa4","status":400,"error":"MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-09 18:11:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: \"2016-05-09 18:11:09\" is malformed at \" 18:11:09\"]; "}},{"index":{"_index":"searchlight-2016_05_10_19_30_41","_type":"OS::Designate::Zone","_id":"bdcb0f05-5fe2-4d0d-a168-5103d147af5e","status":400,"error":"MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-10 19:30:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: \"2016-05-10 19:30:09\" is malformed at \" 19:30:09\"]; "}}]} from (pid=114287) log_request_success /usr/local/lib/python2.7/dist-packages/elasticsearch/connection/base.py:66
2016-05-10 13:30:42.259 ERROR searchlight.cmd.manage [-] Failed to setup index extension os_designate_zone: (u'2 document(s) failed to index.', [{u'index': {u'status': 400, u'_type': u'OS::Designate::Zone', u'_id': u'f4132f97-d477-4e8c-8afd-2ad75838cfa4', u'_index': u'searchlight-2016_05_10_19_30_41', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-09 18:11:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-09 18:11:09" is malformed at " 18:11:09"]; '}}, {u'index': {u'status': 400, u'_type': u'OS::Designate::Zone', u'_id': u'bdcb0f05-5fe2-4d0d-a168-5103d147af5e', u'_index': u'searchlight-2016_05_10_19_30_41', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-10 19:30:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-10 19:30:09" is malformed at " 19:30:09"]; '}}])
2016-05-10 13:30:42.268 INFO elasticsearch [-] DELETE http://127.0.0.1:9200/searchlight-2016_05_10_19_30_41 [status:200 request:0.008s]
2016-05-10 13:30:42.268 DEBUG elasticsearch [-] > None from (pid=114287) log_request_success /usr/local/lib/python2.7/dist-packages/elasticsearch/connection/base.py:65
2016-05-10 13:30:42.268 DEBUG elasticsearch [-] < {"acknowledged":true} from (pid=114287) log_request_success /usr/local/lib/python2.7/dist-packages/elasticsearch/connection/base.py:66
2016-05-10 13:30:42.268 CRITICAL searchlight [-] BulkIndexError: (u'2 document(s) failed to index.', [{u'index': {u'status': 400, u'_type': u'OS::Designate::Zone', u'_id': u'f4132f97-d477-4e8c-8afd-2ad75838cfa4', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-09 18:11:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-09 18:11:09" is malformed at " 18:11:09"]; ', u'_index': u'searchlight-2016_05_10_19_30_41'}}, {u'index': {u'status': 400, u'_type': u'OS::Designate::Zone', u'_id': u'bdcb0f05-5fe2-4d0d-a168-5103d147af5e', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-10 19:30:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-10 19:30:09" is malformed at " 19:30:09"]; ', u'_index': u'searchlight-2016_05_10_19_30_41'}}])

2016-05-10 13:30:42.268 TRACE searchlight Traceback (most recent call last):
2016-05-10 13:30:42.268 TRACE searchlight File "/usr/local/bin/searchlight-manage", line 10, in <module>
2016-05-10 13:30:42.268 TRACE searchlight sys.exit(main())
2016-05-10 13:30:42.268 TRACE searchlight File "/opt/stack/searchlight/searchlight/cmd/manage.py", line 363, in main
2016-05-10 13:30:42.268 TRACE searchlight return CONF.command.action_fn(*func_args, **func_kwargs)
2016-05-10 13:30:42.268 TRACE searchlight File "/opt/stack/searchlight/searchlight/cmd/manage.py", line 223, in sync
2016-05-10 13:30:42.268 TRACE searchlight plugin_obj.initial_indexing(index_name=index_names[gname])
2016-05-10 13:30:42.268 TRACE searchlight File "/opt/stack/searchlight/searchlight/elasticsearch/plugins/base.py", line 142, in initial_indexing
2016-05-10 13:30:42.268 TRACE searchlight self.setup_data(index_name)
2016-05-10 13:30:42.268 TRACE searchlight File "/opt/stack/searchlight/searchlight/elasticsearch/plugins/base.py", line 176, in setup_data
2016-05-10 13:30:42.268 TRACE searchlight index=index)
2016-05-10 13:30:42.268 TRACE searchlight File "/opt/stack/searchlight/searchlight/elasticsearch/plugins/helper.py", line 179, in save_documents
2016-05-10 13:30:42.268 TRACE searchlight raise e
2016-05-10 13:30:42.268 TRACE searchlight BulkIndexError: (u'2 document(s) failed to index.', [{u'index': {u'status': 400, u'_type': u'OS::Designate::Zone', u'_id': u'f4132f97-d477-4e8c-8afd-2ad75838cfa4', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-09 18:11:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-09 18:11:09" is malformed at " 18:11:09"]; ', u'_index': u'searchlight-2016_05_10_19_30_41'}}, {u'index': {u'status': 400, u'_type': u'OS::Designate::Zone', u'_id': u'bdcb0f05-5fe2-4d0d-a168-5103d147af5e', u'error': u'MapperParsingException[failed to parse [created_at]]; nested: MapperParsingException[failed to parse date field [2016-05-10 19:30:09], tried both date format [dateOptionalTime], and timestamp number with locale []]; nested: IllegalArgumentException[Invalid format: "2016-05-10 19:30:09" is malformed at " 19:30:09"]; ', u'_index': u'searchlight-2016_05_10_19_30_41'}}])
2016-05-10 13:30:42.268 TRACE searchlight

Tags: designate
tags: added: designate
description: updated
Changed in searchlight:
importance: Undecided → High
assignee: nobody → Lakshmi N Sampath (lakshmi-sampath)
Steve McLellan (sjmc7)
Changed in searchlight:
importance: High → Critical
Steve McLellan (sjmc7)
Changed in searchlight:
assignee: Lakshmi N Sampath (lakshmi-sampath) → Steve McLellan (sjmc7)
Revision history for this message
Steve McLellan (sjmc7) wrote :

This'll get fixed in designate and not by us, though i will add some test data for designate so this doesn't catch us again.

description: updated
Changed in designate:
importance: Undecided → Critical
assignee: nobody → Graham Hayes (grahamhayes)
milestone: none → newton-2
Revision history for this message
Graham Hayes (grahamhayes) wrote :

found the commit - https://github.com/openstack/designate/commit/7abae80c61f5c6779357c8bcf7e9dcaaa4ed20a3

Will need to revert this in the objects code + adapter rendering.

need to run "datetime.datetime.isoformat(value)" on each field that is a datetime when we are rendering + outputting notifications.

Tim Simmons (timsim)
Changed in designate:
status: New → Triaged
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to designate (master)

Fix proposed to branch: master
Review: https://review.openstack.org/330132

Changed in designate:
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to designate (master)

Reviewed: https://review.openstack.org/330132
Committed: https://git.openstack.org/cgit/openstack/designate/commit/?id=a6d7ee9089160c71db05dffbe0e0f3bf1935ba31
Submitter: Jenkins
Branch: master

commit a6d7ee9089160c71db05dffbe0e0f3bf1935ba31
Author: Graham Hayes <email address hidden>
Date: Wed Jun 15 19:19:52 2016 +0100

    Fix output of datetime objects in API

    We accidentally changed formats in the v2 API in a previous
    commit.

    This forces all text representations of datetime objects to be
    '%Y-%m-%dT%H:%M:%S.%f'

    Change-Id: I2a4b55804d7ed2084d8705844ca63e41ed626bf2
    Closes-Bug: #1579844

Changed in designate:
status: In Progress → Fix Released
Revision history for this message
Travis Tripp (travis-tripp) wrote :

Graham's fix above in Designate has fixed this issue. We don't need to change anything in Searchlight.

Changed in searchlight:
status: New → Invalid
milestone: none → newton-2
Revision history for this message
Davanum Srinivas (DIMS) (dims-v) wrote : Fix included in openstack/designate 3.0.0.0b2

This issue was fixed in the openstack/designate 3.0.0.0b2 development milestone.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.