OS::Nova::Server ignores build to error status update

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

Bug Description

Launched an instance which failed (not sure why). It went into the build state, but then it never transitioned into the Error state. Upon examination of the listener log, found the following:

Skipping update or indexing for aa1983c7-b04c-49f6-a14a-05be2d8ca04f; event contains no useful information from (pid=128305)

Full log:

2016-08-24 17:13:07.119 INFO searchlight.listener [-] Starting OS::Neutron::Port port.delete.end "2016-08-24 23:13:07.116299" project_id:1e653364122d400cb2256f81ac90cd63 id:5e24e60a-bbfb-47e1-9544-911943e22014 network_id:63b7d75f-ef6a-4448-ad92-fb0f61f6a904

2016-08-24 17:13:07.119 DEBUG searchlight.elasticsearch.plugins.neutron.notification_handlers [-] Deleting port information for 5e24e60a-bbfb-47e1-9544-911943e22014; finding routing from (pid=128305) delete

/opt/stack/searchlight/searchlight/elasticsearch/plugins/neutron/notification_handlers.py:133
2016-08-24 17:13:07.121 INFO elasticsearch [-] GET http://127.0.0.1:9200/searchlight-listener/OS%3A%3ANeutron%3A%3APort/_search [status:200 request:0.002s]

2016-08-24 17:13:07.122 DEBUG elasticsearch [-] > {"filter": {"term": {"_id": "5e24e60a-bbfb-47e1-9544-911943e22014_ADMIN"}}, "fields": ["_parent", "_routing"]} from (pid=128305) log_request_success build/bdist.linux-x86_64/egg/elasticsearch/connection/base.py:65
2016-08-24 17:13:07.122 DEBUG elasticsearch [-] < {"took":1,"timed_out":false,"_shards":{"total":1,"successful":1,"failed":0},"hits":{"total":1,"max_score":1.0,"hits":[{"_index":"searchlight-2016_08_16_18_23_39","_type":"OS::Neutron::Port","_id":"5e24e60a-bbfb-47e1-9544-911943e22014_ADMIN","_score":1.0,"fields":{"_parent":"63b7d75f-ef6a-4448-ad92-fb0f61f6a904_ADMIN","_routing":"63b7d75f-ef6a-4448-ad92-fb0f61f6a904_ADMIN"}}]}} from (pid=128305) log_request_success build/bdist.linux-x86_64/egg/elasticsearch/connection/base.py:66

2016-08-24 17:13:07.122 DEBUG searchlight.elasticsearch.plugins.helper [-] Deleting OS::Neutron::Port id 5e24e60a-bbfb-47e1-9544-911943e22014 with parent 63b7d75f-ef6a-4448-ad92-fb0f61f6a904 routing 63b7d75f-ef6a-4448-ad92-fb0f61f6a904_ADMIN from (pid=128305) delete_document_unknown_parent /opt/stack/searchlight/searchlight/elasticsearch/plugins/helper.py:386

2016-08-24 17:13:07.125 INFO elasticsearch [-] POST http://127.0.0.1:9200/searchlight-listener/OS%3A%3ANeutron%3A%3APort/_bulk [status:200 request:0.002s]

2016-08-24 17:13:07.125 DEBUG elasticsearch [-] > {"delete": {"_parent": "63b7d75f-ef6a-4448-ad92-fb0f61f6a904_ADMIN", "_routing": "63b7d75f-ef6a-4448-ad92-fb0f61f6a904_ADMIN", "_id": "5e24e60a-bbfb-47e1-9544-911943e22014_ADMIN"}}
{"delete": {"_parent": "63b7d75f-ef6a-4448-ad92-fb0f61f6a904_USER", "_routing": "63b7d75f-ef6a-4448-ad92-fb0f61f6a904_ADMIN", "_id": "5e24e60a-bbfb-47e1-9544-911943e22014_USER"}}
 from (pid=128305) log_request_success build/bdist.linux-x86_64/egg/elasticsearch/connection/base.py:65

2016-08-24 17:13:07.125 DEBUG elasticsearch [-] < {"took":1,"errors":false,"items":[{"delete":{"_index":"searchlight-2016_08_16_18_23_39","_type":"OS::Neutron::Port","_id":"5e24e60a-bbfb-47e1-9544-911943e22014_ADMIN","_version":472080382080383002,"status":200,"found":true}},{"delete":{"_index":"searchlight-2016_08_16_18_23_39","_type":"OS::Neutron::Port","_id":"5e24e60a-bbfb-47e1-9544-911943e22014_USER","_version":472080382080383002,"status":200,"found":true}}]} from (pid=128305) log_request_success build/bdist.linux-x86_64/egg/elasticsearch/connection/base.py:66

2016-08-24 17:13:07.125 INFO searchlight.listener [-] Finished OS::Neutron::Port port.delete.end "2016-08-24 23:13:07.116299" project_id:1e653364122d400cb2256f81ac90cd63 id:5e24e60a-bbfb-47e1-9544-911943e22014 network_id:63b7d75f-ef6a-4448-ad92-fb0f61f6a904

2016-08-24 17:13:07.385 DEBUG oslo_messaging._drivers.amqpdriver [-] received message with unique_id: bc72d5c2e3784834880e8a246292ca7f from (pid=128305) __call__ /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:196

2016-08-24 17:13:07.386 INFO searchlight.listener [-] Starting OS::Nova::Server compute.instance.update "2016-08-24 23:13:07.383905" project_id:1e653364122d400cb2256f81ac90cd63 id:aa1983c7-b04c-49f6-a14a-05be2d8ca04f state:building state_description:block_device_mapping
2016-08-24 17:13:07.386 DEBUG searchlight.elasticsearch.plugins.nova.notification_handler [-] Attempting partial state update for aa1983c7-b04c-49f6-a14a-05be2d8ca04f matching {'state': u'building', 'new_task_state': 'networking'} from (pid=128305) _partial_state_update /opt/stack/searchlight/searchlight/elasticsearch/plugins/nova/notification_handler.py:219
2016-08-24 17:13:07.388 INFO elasticsearch [-] GET http://127.0.0.1:9200/searchlight-listener/OS%3A%3ANova%3A%3AServer/aa1983c7-b04c-49f6-a14a-05be2d8ca04f_ADMIN [status:200 request:0.001s]

2016-08-24 17:13:07.388 DEBUG elasticsearch [-] > None from (pid=128305) log_request_success build/bdist.linux-x86_64/egg/elasticsearch/connection/base.py:65

2016-08-24 17:13:07.388 DEBUG elasticsearch [-] < {"_index":"searchlight-2016_08_16_18_23_39","_type":"OS::Nova::Server","_id":"aa1983c7-b04c-49f6-a14a-05be2d8ca04f_ADMIN","_version":472080381080381858,"found":true,"_source":{"OS-EXT-STS:task_state":"block_device_mapping","addresses":{},"updated_at":"2016-08-24T23:13:01Z","OS-EXT-SRV-ATTR:user_data":null,"owner":"1e653364122d400cb2256f81ac90cd63","OS-EXT-STS:vm_state":"building","OS-EXT-SRV-ATTR:instance_name":"instance-00000009","OS-EXT-SRV-ATTR:root_device_name":null,"OS-SRV-USG:launched_at":null,"flavor":{"id":"ed149c51-7bda-4c72-815d-5b62d1d5c61a"},"networks":[],"security_groups":[],"OS-SRV-USG:terminated_at":null,"os-extended-volumes:volumes_attached":[],"user_id":"068265fe082940619670401c575ae1cd","OS-EXT-SRV-ATTR:hostname":"cirros","OS-DCF:diskConfig":"AUTO","id":"aa1983c7-b04c-49f6-a14a-05be2d8ca04f","accessIPv4":"","accessIPv6":"","OS-EXT-SRV-ATTR:reservation_id":"r-qc26y904","OS-EXT-STS:power_state":0,"OS-EXT-AZ:availability_zone":"nova","metadata":{},"status":"BUILD","OS-EXT-SRV-ATTR:ramdisk_id":"","updated":"2016-08-24T23:13:01Z","hostId":"","OS-EXT-SRV-ATTR:host":null,"description":"cirros","tags":[],"key_name":"asdf","__searchlight-user-role":"admin","OS-EXT-SRV-ATTR:kernel_id":"","locked":false,"project_id":"1e653364122d400cb2256f81ac90cd63","OS-EXT-SRV-ATTR:hypervisor_hostname":null,"name":"cirros","OS-EXT-SRV-ATTR:launch_index":0,"created":"2016-08-24T23:13:01Z","tenant_id":"1e653364122d400cb2256f81ac90cd63","created_at":"2016-08-24T23:13:01Z","host_status":"","config_drive":""}} from (pid=128305) log_request_success build/bdist.linux-x86_64/egg/elasticsearch/connection/base.py:66

2016-08-24 17:13:07.388 DEBUG searchlight.elasticsearch.plugins.nova.notification_handler [-] Skipping state update for aa1983c7-b04c-49f6-a14a-05be2d8ca04f; precondition 'OS-EXT-STS:task_state' = 'networking' doesn't match 'block_device_mapping' in source from (pid=128305) should_update /opt/stack/searchlight/searchlight/elasticsearch/plugins/nova/notification_handler.py:245

2016-08-24 17:13:07.389 INFO searchlight.listener [-] Finished OS::Nova::Server compute.instance.update "2016-08-24 23:13:07.383905" project_id:1e653364122d400cb2256f81ac90cd63 id:aa1983c7-b04c-49f6-a14a-05be2d8ca04f state:building state_description:block_device_mapping

2016-08-24 17:13:07.483 DEBUG oslo_messaging._drivers.amqpdriver [-] received message with unique_id: c5595b195d5b4b0e9e5da89ffe78b7e3 from (pid=128305) __call__ /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:196

2016-08-24 17:13:07.484 INFO searchlight.listener [-] Starting OS::Nova::Server compute.instance.update "2016-08-24 23:13:07.481768" project_id:1e653364122d400cb2256f81ac90cd63 id:aa1983c7-b04c-49f6-a14a-05be2d8ca04f state:error state_description:-

2016-08-24 17:13:07.484 DEBUG searchlight.elasticsearch.plugins.nova.notification_handler [-] Skipping update or indexing for aa1983c7-b04c-49f6-a14a-05be2d8ca04f; event contains no useful information from (pid=128305) index_from_update /opt/stack/searchlight/searchlight/elasticsearch/plugins/nova/notification_handler.py:204

2016-08-24 17:13:07.484 INFO searchlight.listener [-] Finished OS::Nova::Server compute.instance.update "2016-08-24 23:13:07.481768" project_id:1e653364122d400cb2256f81ac90cd63 id:aa1983c7-b04c-49f6-a14a-05be2d8ca04f state:error state_description:-

Changed in searchlight:
importance: Undecided → Critical
Steve McLellan (sjmc7)
Changed in searchlight:
assignee: nobody → Steve McLellan (sjmc7)
Steve McLellan (sjmc7)
summary: - OS::Nova::Server ignores build --> error status update
+ OS::Nova::Server ignores build to error status update
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to searchlight (master)

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

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

Reviewed: https://review.openstack.org/364009
Committed: https://git.openstack.org/cgit/openstack/searchlight/commit/?id=177818bf9ce6f37799cc746ddf80965b25e34b51
Submitter: Jenkins
Branch: master

commit 177818bf9ce6f37799cc746ddf80965b25e34b51
Author: Steve McLellan <email address hidden>
Date: Wed Aug 31 19:56:10 2016 -0500

    Handle nova error states correctly

    When nova servers transition to error states during build there's
    no final .end event, and the final update notifications were getting
    ignored by the transition state logic. This patch adds a full API index
    call from the final error update event.

    Change-Id: I65f5542d3c9290b321bd2a86e9123d8668ce7ef9
    Closes-Bug: #1616674

Changed in searchlight:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/searchlight 1.0.0.0rc1

This issue was fixed in the openstack/searchlight 1.0.0.0rc1 release candidate.

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.