Bug 1245854

Summary: blivet.errors.DeviceFactoryError: invalid value NotImplemented for size
Product: [Fedora] Fedora Reporter: Adam Williamson <awilliam>
Component: anacondaAssignee: Anaconda Maintenance Team <anaconda-maint-list>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 23CC: anaconda-maint-list, g.kaviyarasu, jonathan, vanmeeuwen+fedora
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard: abrt_hash:155bee7654195e18f43a34bb8a4ba20e8d0ee8469e7fd5a5ce1350cf42286854
Fixed In Version: blivet-1.10-1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-07-27 17:51:43 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
File: anaconda-tb
none
File: anaconda.log
none
File: dnf.log
none
File: environ
none
File: lsblk_output
none
File: nmcli_dev_list
none
File: os_info
none
File: program.log
none
File: storage.log
none
File: syslog
none
File: ifcfg.log
none
File: packaging.log none

Description Adam Williamson 2015-07-23 00:56:04 UTC
Description of problem:
1. Start with two empty disks
2. Boot the 2015-07-17 nightly boot.iso with an updates.img containing all changes to current git master for anaconda and blivet
3. Select both disks as targets and go to custom partitioning
4. Click 'create them automatically'
5. Select the / partition, change its type to RAID
6. Click Update Settings

This is very similar to #1245446.

Version-Release number of selected component:
anaconda-23.16-1

The following was filed automatically by anaconda:
anaconda 23.16-1 exception report
Traceback (most recent call first):
  File "/tmp/updates/blivet/devicefactory.py", line 804, in configure
    raise(e)
  File "/tmp/updates/pyanaconda/ui/gui/spokes/custom.py", line 1879, in _destroy_device
    factory.configure()
  File "/tmp/updates/pyanaconda/ui/gui/spokes/custom.py", line 135, in decorated
    return func(*args, **kwargs)
  File "/tmp/updates/pyanaconda/ui/gui/spokes/custom.py", line 1155, in _save_right_side
    self._destroy_device(device)
  File "/tmp/updates/pyanaconda/ui/gui/spokes/custom.py", line 2654, in on_update_settings_clicked
    self._save_right_side(self._current_selector)
  File "/tmp/updates/pyanaconda/ui/gui/utils.py", line 266, in _run_once_one_arg
    self._func(*args, **kwargs)
blivet.errors.DeviceFactoryError: invalid value NotImplemented for size

Additional info:
addons:         com_redhat_kdump
cmdline:        /usr/bin/python3  /sbin/anaconda
cmdline_file:   BOOT_IMAGE=vmlinuz initrd=initrd.img inst.stage2=hd:LABEL=Fedora-23-x86_64 quiet inst.updates=https://www.happyassassin.net/temp/updates.img
dnf.rpm.log:    Jul 23 00:52:06 INFO --- logging initialized ---
executable:     /sbin/anaconda
hashmarkername: anaconda
kernel:         4.2.0-0.rc2.git1.1.fc23.x86_64
product:        Fedora
release:        Cannot get release name.
type:           anaconda
version:        23

Comment 1 Adam Williamson 2015-07-23 00:56:07 UTC
Created attachment 1055126 [details]
File: anaconda-tb

Comment 2 Adam Williamson 2015-07-23 00:56:08 UTC
Created attachment 1055127 [details]
File: anaconda.log

Comment 3 Adam Williamson 2015-07-23 00:56:09 UTC
Created attachment 1055128 [details]
File: dnf.log

Comment 4 Adam Williamson 2015-07-23 00:56:10 UTC
Created attachment 1055129 [details]
File: environ

Comment 5 Adam Williamson 2015-07-23 00:56:11 UTC
Created attachment 1055130 [details]
File: lsblk_output

Comment 6 Adam Williamson 2015-07-23 00:56:11 UTC
Created attachment 1055131 [details]
File: nmcli_dev_list

Comment 7 Adam Williamson 2015-07-23 00:56:12 UTC
Created attachment 1055132 [details]
File: os_info

Comment 8 Adam Williamson 2015-07-23 00:56:13 UTC
Created attachment 1055133 [details]
File: program.log

Comment 9 Adam Williamson 2015-07-23 00:56:15 UTC
Created attachment 1055134 [details]
File: storage.log

Comment 10 Adam Williamson 2015-07-23 00:56:16 UTC
Created attachment 1055135 [details]
File: syslog

Comment 11 Adam Williamson 2015-07-23 00:56:17 UTC
Created attachment 1055136 [details]
File: ifcfg.log

Comment 12 Adam Williamson 2015-07-23 00:56:18 UTC
Created attachment 1055137 [details]
File: packaging.log

Comment 13 Adam Williamson 2015-07-23 04:40:09 UTC
This is failing somewhere in this block in PartitionSetFactory.configure():

        log.debug("adding a %s with size %s",
                  self.parent_factory.size_set_class.__name__, total_space)
        size_set = self.parent_factory.size_set_class(members, total_space)
        self.storage.size_sets.append(size_set)
        for member in members[:]:
            member = member.raw_device
            member.req_max_size = size_set.size

custom.py _destroy_device() creates an LVMFactory which gets a child PartitionSetFactory, and it's while that child factory is getting configured that we hit the crash. We hit the "adding a %s with size %s" log.debug, but we don't hit a log.debug added just before the next step - so this seems to be where it explodes. Looking into it further.

Comment 14 Adam Williamson 2015-07-23 05:00:48 UTC
Hum, scratch that...must've messed up an updates.img. I found a better traceback in the anaconda-tb now:

21:21:35,652 CRIT anaconda: Traceback (most recent call last):

  File "/tmp/updates/blivet/devicefactory.py", line 794, in configure
    self._configure()

  File "/tmp/updates/blivet/devicefactory.py", line 1344, in _configure
    super(LVMFactory, self)._configure()

  File "/tmp/updates/blivet/devicefactory.py", line 818, in _configure
    self.child_factory.configure()

  File "/tmp/updates/blivet/devicefactory.py", line 1140, in configure
    self._post_create()

  File "/tmp/updates/blivet/devicefactory.py", line 933, in _post_create
    doPartitioning(self.storage)

  File "/tmp/updates/blivet/partitioning.py", line 550, in doPartitioning
    growPartitions(disks, partitions, free, size_sets=storage.size_sets)

  File "/tmp/updates/blivet/partitioning.py", line 1694, in growPartitions
    manageSizeSets(size_sets, chunks)

  File "/tmp/updates/blivet/partitioning.py", line 1598, in manageSizeSets
    chunk.reclaim(request, extra)

  File "/tmp/updates/blivet/partitioning.py", line 1077, in reclaim
    log.debug("reclaim: %s %d (%s)", request, amount, self.lengthToSize(amount))

  File "/tmp/updates/blivet/partitioning.py", line 1358, in lengthToSize
    return sectorsToSize(length, self.sectorSize)

  File "/tmp/updates/blivet/partitioning.py", line 298, in sectorsToSize
    return Size(sectors * sectorSize)

  File "/tmp/updates/blivet/size.py", line 316, in __mul__
    return Size(Decimal.__mul__(self, other))

  File "/tmp/updates/blivet/size.py", line 277, in __new__
    raise ValueError("invalid value %s for size" % value)

ValueError: invalid value NotImplemented for size

Comment 15 Adam Williamson 2015-07-23 06:24:41 UTC
OK, so the problem is that when lengthToSize calls 'sectorsToSize(length, self.sectorSize)', length is a float. Here's a simple reproducer:

from blivet.size import Size
fl = float(1)
sz = Size(1)
Size(fl*sz)

That raises an exception, and that's basically what's happening here. sectorsToSize gets hit a whole lot and almost always the type of the first param is int, and that works - but just on this path the type of the first param is float and it explodes.

Now I get to figure out why the hell length is a float! This is fun, if by 'fun' you mean 'no fun at all'.

Comment 16 Adam Williamson 2015-07-23 06:35:55 UTC
Aha. OK. I got it. It's a py2 vs. py3 thing. The problem is here, in manageSizeSets:

                        extra = -chunk.sizeToLength(needed) / len(ss.devices)

in context, -chunk.sizeToLength is an int - in my test case it's 2162163712 - and so, obviously, will be len(ss.devices). Now, observe:

[adamw@adam anaconda (master *%)]$ python2
Python 2.7.10 (default, Jun 29 2015, 16:02:04) 
[GCC 5.1.1 20150618 (Red Hat 5.1.1-4)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> type(2162163712/2)
<type 'int'>
>>> 
[adamw@adam anaconda (master *%)]$ python3
Python 3.4.3 (default, Jun 29 2015, 12:16:01) 
[GCC 5.1.1 20150618 (Red Hat 5.1.1-4)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> type(2162163712/2)
<class 'float'>
>>> 

i.e. in python2, 'int / int' returns an int. In python3, 'int / int' returns a float.

I think the fix for this should be as simple as:

-                        extra = -chunk.sizeToLength(needed) / len(ss.devices)
+                        extra = -chunk.sizeToLength(needed) // len(ss.devices)

Comment 17 Adam Williamson 2015-07-23 06:57:48 UTC
*** Bug 1245446 has been marked as a duplicate of this bug. ***

Comment 18 Adam Williamson 2015-07-23 06:58:12 UTC
https://github.com/rhinstaller/blivet/pull/177

Comment 19 Adam Williamson 2015-07-24 06:50:12 UTC
Merged by dlehman, will be fixed in next blivet.

Comment 20 Adam Williamson 2015-07-27 17:51:43 UTC
This is indeed fixed in TC2, openQA and manual testing confirm it.