logging exception in lvm driver

Bug #1189455 reported by Michael Kerrin on 2013-06-10
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Cinder
High
Avishay Traeger

Bug Description

I found the following exception in my devstack instance:

2013-06-10 08:22:20.195 25464 DEBUG cinder.manager [-] Running periodic task VolumeManager._report_driver_status periodic_tasks /opt/stack/cinder/cinder/manager.py:164
2013-06-10 08:22:20.195 25464 INFO cinder.volume.manager [-] Updating volume status
2013-06-10 08:22:20.196 25464 DEBUG cinder.volume.drivers.lvm [-] Updating volume status _update_volume_status /opt/stack/cinder/cinder/volume/drivers/lvm.py:561
2013-06-10 08:22:20.196 25464 DEBUG cinder.utils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf vgs --noheadings --nosuffix --unit=G -o n\
ame,size,free stack-volumes execute /opt/stack/cinder/cinder/utils.py:169
2013-06-10 08:22:20.412 25464 DEBUG cinder.utils [-] Result was 1 execute /opt/stack/cinder/cinder/utils.py:186
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 846, in emit
    msg = self.format(record)
  File "/opt/stack/cinder/cinder/openstack/common/log.py", line 551, in format
    return logging.StreamHandler.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 723, in format
    return fmt.format(record)
  File "/opt/stack/cinder/cinder/openstack/common/log.py", line 515, in format
    return logging.Formatter.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 464, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.7/logging/__init__.py", line 328, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file lvm.py, line 584
2013-06-10 08:23:20.415 25464 DEBUG cinder.manager [-] Running periodic task VolumeManager._publish_service_capabilities periodic_tasks /opt/stack/cinder/cinder/manage\
r.py:164
2013-06-10 08:23:20.416 25464 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /opt/stack/cinder/cinder/manager.py:216
2013-06-10 08:23:20.416 25464 DEBUG cinder.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... fanout_cast /opt/stack/cinder/cinder/openstack/common/rpc/a\
mqp.py:632
2013-06-10 08:23:20.417 25464 DEBUG cinder.openstack.common.rpc.amqp [-] UNIQUE_ID is 26bbf211238b4a0ebff2d102e278431c. _add_unique_id /opt/stack/cinder/cinder/opensta\
ck/common/rpc/amqp.py:337
2013-06-10 08:23:20.419 25464 DEBUG amqp [-] Closed channel #1 _do_close /usr/local/lib/python2.7/dist-packages/amqp/channel.py:88
2013-06-10 08:23:20.420 25464 DEBUG amqp [-] using channel_id: 1 __init__ /usr/local/lib/python2.7/dist-packages/amqp/channel.py:70
2013-06-10 08:23:20.424 25464 DEBUG amqp [-] Channel open _open_ok /usr/local/lib/python2.7/dist-packages/amqp/channel.py:420
2013-06-10 08:23:20.424 25464 DEBUG cinder.manager [-] Running periodic task VolumeManager._report_driver_status periodic_tasks /opt/stack/cinder/cinder/manager.py:164
2013-06-10 08:23:20.424 25464 INFO cinder.volume.manager [-] Updating volume status
2013-06-10 08:23:20.425 25464 DEBUG cinder.volume.drivers.lvm [-] Updating volume status _update_volume_status /opt/stack/cinder/cinder/volume/drivers/lvm.py:561
2013-06-10 08:23:20.425 25464 DEBUG cinder.utils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf vgs --noheadings --nosuffix --unit=G -o n\
ame,size,free stack-volumes execute /opt/stack/cinder/cinder/utils.py:169
2013-06-10 08:23:20.648 25464 DEBUG cinder.utils [-] Result was 1 execute /opt/stack/cinder/cinder/utils.py:186
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 846, in emit
    msg = self.format(record)
  File "/opt/stack/cinder/cinder/openstack/common/log.py", line 551, in format
    return logging.StreamHandler.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 723, in format
    return fmt.format(record)
  File "/opt/stack/cinder/cinder/openstack/common/log.py", line 515, in format
    return logging.Formatter.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 464, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.7/logging/__init__.py", line 328, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file lvm.py, line 584

Due to the error in logging, I have no idea what the original error in the subprocess was.

Changed in cinder:
status: New → Confirmed
importance: Undecided → High
assignee: nobody → Avishay Traeger (avishay-il)

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

Changed in cinder:
status: Confirmed → In Progress

Reviewed: https://review.openstack.org/32529
Committed: http://github.com/openstack/cinder/commit/03b9cf662a86c97f3673530a4c0ed371d061a188
Submitter: Jenkins
Branch: master

commit 03b9cf662a86c97f3673530a4c0ed371d061a188
Author: Avishay Traeger <email address hidden>
Date: Tue Jun 11 09:10:37 2013 +0300

    Fix LVM logging error.

    Missed a %s, which caused an exception.

    Change-Id: Ib6fcabebdcf70430f3e46095da6c5e13b3e3a4ff
    Fixes: bug 1189455

Changed in cinder:
status: In Progress → Fix Committed
Thierry Carrez (ttx) on 2013-07-17
Changed in cinder:
milestone: none → havana-2
status: Fix Committed → Fix Released
Thierry Carrez (ttx) on 2013-10-17
Changed in cinder:
milestone: havana-2 → 2013.2
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers