Bug 1085057 - Using string formatting operator in logging method argument expressions
Summary: Using string formatting operator in logging method argument expressions
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: python-blivet
Version: 22
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: mulhern
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:a6e83592259a4fd92683b9efbe8...
Depends On:
Blocks: 1085474
TreeView+ depends on / blocked
 
Reported: 2014-04-07 17:15 UTC by Kevin R. Porter
Modified: 2015-06-23 15:49 UTC (History)
7 users (show)

Fixed In Version: python-blivet-0.48
Clone Of:
: 1085474 (view as bug list)
Environment:
Last Closed: 2015-06-23 15:49:49 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: anaconda-tb (435.99 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: anaconda.log (5.32 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: environ (538 bytes, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: journalctl (223.38 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: lsblk_output (2.81 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: nmcli_dev_list (1.42 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: os_info (381 bytes, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: program.log (48.52 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: storage.log (136.31 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details
File: ifcfg.log (6.56 KB, text/plain)
2014-04-07 17:15 UTC, Kevin R. Porter
no flags Details

Description Kevin R. Porter 2014-04-07 17:15:03 UTC
Description of problem:
On an Asus P5Q-EM motherboard w/E8600 cpu, and a pair of identical seagate hdd's set up in the BIOS as a RAID-1 mirror set.

Booted from a 4GB USB stick created elsewhere with 
livecd-iso-to-disk --format --reset-mbr fedora-live-desktop.iso  /dev/sdd

USB booted to desktop, then  selected "install to hard disk", language selection screen comes up, wait a few seconds and anaconda declares the error.

Version-Release number of selected component:
anaconda-core-21.31-1.fc21.x86_64

The following was filed automatically by anaconda:
anaconda 21.31-1 exception report
Traceback (most recent call first):
  File "/usr/lib/python2.7/site-packages/blivet/devicelibs/mdraid.py", line 59, in get_raw_array_size
    raise MDRaidError("get_raw_array_size is not defined for level container.")
  File "/usr/lib/python2.7/site-packages/blivet/devices.py", line 3260, in rawArraySize
    smallestMemberSize)
  File "/usr/lib/python2.7/site-packages/blivet/devices.py", line 3266, in superBlockSize
    return mdraid.get_raid_superblock_size(self.rawArraySize,
  File "/usr/lib/python2.7/site-packages/blivet/devices.py", line 3290, in size
    smallestMemberSize = self.smallestMember.size - self.superBlockSize
  File "/usr/lib/python2.7/site-packages/blivet/devices.py", line 575, in __str__
    s = "%s %s %s" % (exist, self.size, super(StorageDevice, self).__str__())
  File "/usr/lib/python2.7/site-packages/blivet/storage_log.py", line 45, in log_method_return
    logging.getLogger("blivet").debug(fmt % fmt_args)
  File "/usr/lib/python2.7/site-packages/blivet/devicetree.py", line 2190, in getDeviceByUuid
    log_method_return(self, found)
  File "/usr/lib/python2.7/site-packages/blivet/devicetree.py", line 1509, in handleUdevMDMemberFormat
    md_array = self.getDeviceByUuid(device.format.mdUuid, incomplete=True)
  File "/usr/lib/python2.7/site-packages/blivet/devicetree.py", line 1800, in handleUdevDeviceFormat
    self.handleUdevMDMemberFormat(info, device)
  File "/usr/lib/python2.7/site-packages/blivet/devicetree.py", line 1194, in addUdevDevice
    self.handleUdevDeviceFormat(info, device)
  File "/usr/lib/python2.7/site-packages/blivet/devicetree.py", line 2083, in _populate
    self.addUdevDevice(dev)
  File "/usr/lib/python2.7/site-packages/blivet/devicetree.py", line 2019, in populate
    self._populate()
  File "/usr/lib/python2.7/site-packages/blivet/__init__.py", line 429, in reset
    self.devicetree.populate(cleanupOnly=cleanupOnly)
  File "/usr/lib/python2.7/site-packages/blivet/__init__.py", line 146, in storageInitialize
    storage.reset()
  File "/usr/lib64/python2.7/threading.py", line 766, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib64/python2.7/site-packages/pyanaconda/threads.py", line 227, in run
    threading.Thread.run(self, *args, **kwargs)
MDRaidError: get_raw_array_size is not defined for level container.

Additional info:
cmdline:        /usr/bin/python  /sbin/anaconda --liveinst --method=livecd:///dev/mapper/live-base
cmdline_file:   initrd=initrd0.img root=live:UUID=9082-6045 rootfstype=vfat rw rd.live.image overlay=UUID=9082-6045 quiet  rhgb rd.luks=0 rd.md=0 rd.dm=0  BOOT_IMAGE=vmlinuz0 
executable:     /sbin/anaconda
hashmarkername: anaconda
kernel:         3.15.0-0.rc0.git9.1.fc21.x86_64
other involved packages: python-blivet-0.47-1.fc21.noarch, python-libs-2.7.6-4.fc21.x86_64
product:        Fedora
release:        Fedora release 21 (Rawhide)
type:           anaconda
version:        rawhide

Comment 1 Kevin R. Porter 2014-04-07 17:15:05 UTC
Created attachment 883702 [details]
File: anaconda-tb

Comment 2 Kevin R. Porter 2014-04-07 17:15:07 UTC
Created attachment 883703 [details]
File: anaconda.log

Comment 3 Kevin R. Porter 2014-04-07 17:15:08 UTC
Created attachment 883704 [details]
File: environ

Comment 4 Kevin R. Porter 2014-04-07 17:15:11 UTC
Created attachment 883705 [details]
File: journalctl

Comment 5 Kevin R. Porter 2014-04-07 17:15:13 UTC
Created attachment 883706 [details]
File: lsblk_output

Comment 6 Kevin R. Porter 2014-04-07 17:15:14 UTC
Created attachment 883707 [details]
File: nmcli_dev_list

Comment 7 Kevin R. Porter 2014-04-07 17:15:16 UTC
Created attachment 883708 [details]
File: os_info

Comment 8 Kevin R. Porter 2014-04-07 17:15:18 UTC
Created attachment 883709 [details]
File: program.log

Comment 9 Kevin R. Porter 2014-04-07 17:15:19 UTC
Created attachment 883710 [details]
File: storage.log

Comment 10 Kevin R. Porter 2014-04-07 17:15:21 UTC
Created attachment 883711 [details]
File: ifcfg.log

Comment 11 Kevin R. Porter 2014-04-08 01:53:46 UTC
Oddly enough, while F21 (bug occurs on Rawhide 20140406 X64 "live desktop" nightly build) chokes on my Intel BIOS raid-1 mirror set...the older
F20 installs just fine on the same hardware.  I.e. this bug would appear to be something new in Anaconda's code since F20?

Comment 12 mulhern 2014-04-08 13:00:39 UTC
There are a few levels of problem here:

1) In log_method_return() the debug() method is called using the format operator. It is possible to pass the fmt_args as arguments to the debug() method, which ought to cause the exception to be logged instead of raised. pylint did not report W1201 for some reason for this line.
2) An exception is raised when get_raw_array_size() is called for a container object. Should this choice itself be re-evaluated? If not:
3) Then we cannot assume that superBlockSize() must always succeed, as self.rawArraySize() may raise an exception. We need to decide whether the exception should be handled in superBlockSize or rawArraySize and how.

Comment 13 Jaroslav Reznik 2015-03-03 17:12:30 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 22 development cycle.
Changing version to '22'.

More information and reason for this action is here:
https://fedoraproject.org/wiki/Fedora_Program_Management/HouseKeeping/Fedora22


Note You need to log in before you can comment on or make changes to this bug.