Nova Compute generates stack traces on startup trying to talk to conductor

Bug #1154232 reported by Sean Dague
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Medium
Russell Bryant

Bug Description

Every single startup of nova-compute in any tempest run starts with the following stack trace in the logs:

2013-03-08 17:01:57.139 ERROR nova.openstack.common.rpc.common [req-76037107-4c47-47f7-b9cd-7b3e9e7e1650 None None] Timed out waiting for RPC response: timed out
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common Traceback (most recent call last):
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/opt/stack/new/nova/nova/openstack/common/rpc/impl_kombu.py", line 563, in ensure
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common return method(*args, **kwargs)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/opt/stack/new/nova/nova/openstack/common/rpc/impl_kombu.py", line 643, in _consume
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common return self.connection.drain_events(timeout=timeout)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 175, in drain_events
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common return self.transport.drain_events(self.connection, **kwargs)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 238, in drain_events
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common return connection.drain_events(**kwargs)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 57, in drain_events
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common return self.wait_multi(self.channels.values(), timeout=timeout)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 63, in wait_multi
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common chanmap.keys(), allowed_methods, timeout=timeout)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 120, in _wait_multiple
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common channel, method_sig, args, content = read_timeout(timeout)
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 94, in read_timeout
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common return self.method_reader.read_method()
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common raise m
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common timeout: timed out
2013-03-08 17:01:57.139 11470 TRACE nova.openstack.common.rpc.common
2013-03-08 17:01:57.148 WARNING nova.conductor.api [req-76037107-4c47-47f7-b9cd-7b3e9e7e1650 None None] Timed out waiting for nova-conductor. Is it running? Or did this service start before nova-conductor?
2013-03-08 17:01:57.148 DEBUG nova.openstack.common.rpc.amqp [req-76037107-4c47-47f7-b9cd-7b3e9e7e1650 None None] Making synchronous call on conductor ... multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:541
2013-03-08 17:01:57.149 DEBUG nova.openstack.common.rpc.amqp [req-76037107-4c47-47f7-b9cd-7b3e9e7e1650 None None] MSG_ID is 334393ad8374485ab0350037a2f09ecb multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:544

If this is normal behavior we should suppress this stack trace, because it's a big ugly red herring in the code.

Tags: stacktrace
Sean Dague (sdague)
Changed in nova:
status: New → Confirmed
importance: Undecided → Medium
tags: added: stacktrace
Changed in nova:
milestone: none → grizzly-rc1
Revision history for this message
Sean Dague (sdague) wrote :

Looks like this was fixed prior to March 11th but after March 8th

Changed in nova:
status: Confirmed → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

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

Changed in nova:
status: Fix Released → In Progress
assignee: nobody → Russell Bryant (russellb)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.openstack.org/24226
Committed: http://github.com/openstack/nova/commit/d984b0b0bcbd17567f127395c8b890cddd9edd30
Submitter: Jenkins
Branch: master

commit d984b0b0bcbd17567f127395c8b890cddd9edd30
Author: Russell Bryant <email address hidden>
Date: Tue Mar 12 14:24:49 2013 -0400

    Sync rpc from oslo-incubator.

    Changes include:

     * Fix Copyright Headers - Rename LLC to Foundation
     * Preserve exceptions in impl_zmq.
     * Don't log a traceback on rpc call timeout.
     * Redis-based matchmaker
     * AMQP: skip duplicate messages
     * some other minor fixes / cleanups

    Fix bug 1154232.

    Change-Id: I8afb6b9a919fca34b4a93f7fad1551a023eba6b2

Changed in nova:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in nova:
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in nova:
milestone: grizzly-rc1 → 2013.1
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.