KeyError: 'uuid' trace in n-cpu logs when logging with instance=instance kwarg

Bug #1444728 reported by Matt Riedemann
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
High
Matt Riedemann
Kilo
Fix Released
High
Unassigned
oslo.log
Invalid
Undecided
Matt Riedemann

Bug Description

This is with oslo.log 1.0.0:

http://logs.openstack.org/83/172083/7/gate/gate-tempest-dsvm-neutron-full/bdb2cf0/logs/screen-n-cpu.txt.gz#_2015-04-15_13_49_06_485

Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit
    msg = self.format(record)
  File "/usr/local/lib/python2.7/dist-packages/oslo_log/handlers.py", line 69, in format
    return logging.StreamHandler.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format
    return fmt.format(record)
  File "/usr/local/lib/python2.7/dist-packages/oslo_log/formatters.py", line 182, in format
    % instance)
KeyError: 'uuid'

The change was made here: https://review.openstack.org/#/c/160007/

Looks like that should be formatting with a dict using the uuid key.

Revision history for this message
Matt Riedemann (mriedem) wrote :

These are the default log format options:

    # NOTE(mikal): there are two options here because sometimes we are handed
    # a full instance (and could include more information), and other times we
    # are just handed a UUID for the instance.
    cfg.StrOpt('instance_format',
               default='[instance: %(uuid)s] ',
               help='The format for an instance that is passed with the log '
                    'message.'),
    cfg.StrOpt('instance_uuid_format',
               default='[instance: %(uuid)s] ',
               help='The format for an instance UUID that is passed with the '
                    'log message.'),

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to oslo.log (master)

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

Changed in oslo.log:
assignee: nobody → Matt Riedemann (mriedem)
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on oslo.log (master)

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/174128
Reason: It's a problem in the nova v4 proxy code:

http://git.openstack.org/cgit/openstack/nova/tree/nova/compute/manager.py#n6584

Revision history for this message
Matt Riedemann (mriedem) wrote :

It's a bug in the nova v4 compute proxy code, it's passing the args in the wrong order:

http://git.openstack.org/cgit/openstack/nova/tree/nova/compute/manager.py#n6584

Changed in oslo.log:
status: In Progress → Invalid
Changed in nova:
status: New → Triaged
assignee: nobody → Matt Riedemann (mriedem)
importance: Undecided → High
tags: added: kilo-rc-potential
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/174524

Changed in nova:
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/kilo)

Fix proposed to branch: stable/kilo
Review: https://review.openstack.org/174605

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.openstack.org/174524
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=e55f746ea8590cce7c2b07a023197f369251a7ef
Submitter: Jenkins
Branch: master

commit e55f746ea8590cce7c2b07a023197f369251a7ef
Author: Matt Riedemann <email address hidden>
Date: Thu Apr 16 11:08:50 2015 -0700

    Use kwargs from compute v4 proxy change_instance_metadata

    The args were passed to the compute manager method in the wrong order.
    We noticed this in the gate with KeyError: 'uuid' in the logs because of
    the LOG.debug statement in change_instance_metadata. Just use kwargs
    like rpcapi would normally.

    There isn't a unit test for this since the v4 proxy code goes away in
    liberty, this is for getting it into stable/kilo.

    Closes-Bug: #1444728

    Change-Id: Ic988f48d99e626ee5773c97904e09dbf00c5414a

Changed in nova:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/kilo)

Reviewed: https://review.openstack.org/174605
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=8ebd515aa94ed399074a3b55bd36fd8cd579a499
Submitter: Jenkins
Branch: stable/kilo

commit 8ebd515aa94ed399074a3b55bd36fd8cd579a499
Author: Matt Riedemann <email address hidden>
Date: Thu Apr 16 11:08:50 2015 -0700

    Use kwargs from compute v4 proxy change_instance_metadata

    The args were passed to the compute manager method in the wrong order.
    We noticed this in the gate with KeyError: 'uuid' in the logs because of
    the LOG.debug statement in change_instance_metadata. Just use kwargs
    like rpcapi would normally.

    There isn't a unit test for this since the v4 proxy code goes away in
    liberty, this is for getting it into stable/kilo.

    Closes-Bug: #1444728

    Change-Id: Ic988f48d99e626ee5773c97904e09dbf00c5414a
    (cherry picked from commit e55f746ea8590cce7c2b07a023197f369251a7ef)

Thierry Carrez (ttx)
tags: removed: kilo-rc-potential
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/179284

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)
Download full text (18.1 KiB)

Reviewed: https://review.openstack.org/179284
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=5228d4e418734164ffa5ccd91d2865d9cc659c00
Submitter: Jenkins
Branch: master

commit 906ab9d6522b3559b4ad36d40dec3af20397f223
Author: He Jie Xu <email address hidden>
Date: Thu Apr 16 07:09:34 2015 +0800

    Update rpc version aliases for kilo

    Update all of the rpc client API classes to include a version alias
    for the latest version implemented in Kilo. This alias is needed when
    doing rolling upgrades from Kilo to Liberty. With this in place, you can
    ensure all services only send messages that both Kilo and Liberty will
    understand.

    Closes-Bug: #1444745

    Conflicts:
     nova/conductor/rpcapi.py

    NOTE(alex_xu): The conflict is due to there are some logs already added
    into the master.

    Change-Id: I2952aec9aae747639aa519af55fb5fa25b8f3ab4
    (cherry picked from commit 78a8b5802ca148dcf37c5651f75f2126d261266e)

commit f191a2147a21c7e50926b288768a96900cf4c629
Author: Hans Lindgren <email address hidden>
Date: Fri Apr 24 13:10:39 2015 +0200

    Add security group calls missing from latest compute rpc api version bump

    The recent compute rpc api version bump missed out on the security group
    related calls that are part of the api.

    One possible reason is that both compute and security group client side
    rpc api:s share a single target, which is of little value and only cause
    mistakes like this.

    This change eliminates future problems like this by combining them into
    one to get a 1:1 relationship between client and server api:s.

    Change-Id: I9207592a87fab862c04d210450cbac47af6a3fd7
    Closes-Bug: #1448075
    (cherry picked from commit bebd00b117c68097203adc2e56e972d74254fc59)

commit a2872a9262985bd0ee2c6df4f7593947e0516406
Author: Dan Smith <email address hidden>
Date: Wed Apr 22 09:02:03 2015 -0700

    Fix migrate_flavor_data() to catch instances with no instance_extra rows

    The way the query was being performed previously, we would not see any
    instances that didn't have a row in instance_extra. This could happen if
    an instance hasn't been touched for several releases, or if the data
    set is old.

    The fix is a simple change to use outerjoin instead of join. This patch
    includes a test that ensures that instances with no instance_extra rows
    are included in the migration. If we query an instance without such a
    row, we create it before doing a save on the instance.

    Closes-Bug: #1447132
    Change-Id: I2620a8a4338f5c493350f26cdba3e41f3cb28de7
    (cherry picked from commit 92714accc49e85579f406de10ef8b3b510277037)

commit e3a7b83834d1ae2064094e9613df75e3b07d77cd
Author: OpenStack Proposal Bot <email address hidden>
Date: Thu Apr 23 02:18:41 2015 +0000

    Updated from global requirements

    Change-Id: I5d4acd36329fe2dccb5772fed3ec55b442597150

commit 8c9b5e620eef3233677b64cd234ed2551e6aa182
Author: Divya <email address hidden>
Date: Tue Apr 21 08:26:29 2015 +0200

    Control create/delete flavor api permissions using policy.json

    The permissions of ...

Thierry Carrez (ttx)
Changed in nova:
milestone: none → liberty-1
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in nova:
milestone: liberty-1 → 12.0.0
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.