Attachment 1447891 Details for Bug 1586148 – File: anaconda.log

File: anaconda.log

anaconda.log (text/plain), 35.20 KB, created by Paul Whalen on 2018-06-05 15:15:38 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Paul Whalen

Created: 2018-06-05 15:15:38 UTC

Size: 35.20 KB

patch

obsolete

>10:30:38,995 INF main: /sbin/anaconda 29.15-1.fc29
>10:30:42,221 INF isys: 1136848 kB (1110 MB) are available
>10:30:42,444 INF startup_utils: check_memory(): total:1110, needed:320, graphical:410
>10:30:42,637 INF main: anaconda called with cmdline = ['/sbin/anaconda']
>10:30:42,647 INF main: Default encoding = utf-8 
>10:30:42,923 INF dbus.connection: Connecting to a default bus at unix:abstract=/tmp/dbus-Z4KgDyloxU,guid=895f84d9e9a206e0abc799835af570d2.
>10:30:50,865 INF startup_utils: Waiting 600 sec for modules to be started.
>10:30:52,004 INF startup_utils: Waiting 599 sec for modules to be started.
>10:30:53,035 INF startup_utils: Waiting 598 sec for modules to be started.
>10:30:54,076 INF startup_utils: Waiting 597 sec for modules to be started.
>10:30:55,133 INF startup_utils: Waiting 596 sec for modules to be started.
>10:30:56,187 INF startup_utils: Waiting 595 sec for modules to be started.
>10:30:57,243 INF startup_utils: Waiting 594 sec for modules to be started.
>10:30:58,297 INF startup_utils: Waiting 593 sec for modules to be started.
>10:30:59,347 INF startup_utils: Waiting 592 sec for modules to be started.
>10:31:00,394 INF startup_utils: Waiting 591 sec for modules to be started.
>10:31:01,449 INF startup_utils: Waiting 590 sec for modules to be started.
>10:31:02,498 INF startup_utils: Waiting 589 sec for modules to be started.
>10:31:03,565 INF startup_utils: Waiting 588 sec for modules to be started.
>10:31:04,626 INF startup_utils: Waiting 587 sec for modules to be started.
>10:31:05,710 INF startup_utils: Waiting 586 sec for modules to be started.
>10:31:06,766 INF startup_utils: Waiting 585 sec for modules to be started.
>10:31:07,809 INF startup_utils: Waiting 584 sec for modules to be started.
>10:31:08,860 INF startup_utils: Waiting 583 sec for modules to be started.
>10:31:09,911 INF startup_utils: Waiting 582 sec for modules to be started.
>10:31:10,982 INF startup_utils: Waiting 581 sec for modules to be started.
>10:31:12,034 INF startup_utils: Waiting 580 sec for modules to be started.
>10:31:13,085 INF startup_utils: Waiting 579 sec for modules to be started.
>10:31:14,137 INF startup_utils: Waiting 578 sec for modules to be started.
>10:31:15,205 INF startup_utils: Waiting 577 sec for modules to be started.
>10:31:16,272 INF startup_utils: Waiting 576 sec for modules to be started.
>10:31:17,412 INF startup_utils: Waiting 575 sec for modules to be started.
>10:31:18,557 INF startup_utils: Waiting 574 sec for modules to be started.
>10:31:19,670 INF startup_utils: Waiting 573 sec for modules to be started.
>10:31:20,705 INF startup_utils: Waiting 572 sec for modules to be started.
>10:31:21,748 INF startup_utils: Waiting 571 sec for modules to be started.
>10:31:22,794 INF startup_utils: Waiting 570 sec for modules to be started.
>10:31:23,852 INF startup_utils: Waiting 569 sec for modules to be started.
>10:31:24,890 INF startup_utils: Waiting 568 sec for modules to be started.
>10:31:25,926 INF startup_utils: Waiting 567 sec for modules to be started.
>10:31:26,999 INF startup_utils: Waiting 566 sec for modules to be started.
>10:31:28,053 INF startup_utils: Waiting 565 sec for modules to be started.
>10:31:29,086 INF startup_utils: Waiting 564 sec for modules to be started.
>10:31:30,177 INF startup_utils: Waiting 563 sec for modules to be started.
>10:31:31,211 INF startup_utils: Waiting 562 sec for modules to be started.
>10:31:33,769 INF startup_utils: Parsing kickstart: /usr/share/anaconda/interactive-defaults.ks
>10:31:34,632 ERR core.util: Failed to import module docker from path /usr/share/anaconda/addons/com_redhat_docker/ks/docker.py in collect: No module named 'pyanaconda.iutil'
>10:31:40,340 WRN kickstart: Command firstboot will be parsed in DBus module.
>10:31:40,768 DBG localization: setting locale to: en_US.UTF-8
>10:31:40,982 DBG network: devices found ['eth0']
>10:31:41,215 DBG network: ensure single initramfs connections
>10:31:42,311 DBG network: apply kickstart
>10:31:42,319 DBG network: create missing ifcfg files
>10:31:43,869 DBG network: set real ONBOOT value
>10:31:43,933 INF threading: Running Thread: AnaWaitForConnectingNMThread (-1312852896)
>10:31:43,985 DBG anaconda: setting display mode to GUI
>10:31:44,178 INF anaconda: Display mode is set to 'interactive graphical mode'.
>10:31:44,233 INF isys: 1136848 kB (1110 MB) are available
>10:31:44,429 INF startup_utils: check_memory(): total:1110, needed:320, graphical:410
>10:31:44,449 DBG core.util: Setting timeout 60 seconds for starting X.
>10:31:44,937 INF network: got 0 NTP servers from DHCP
>10:31:45,031 INF threading: Thread Done: AnaWaitForConnectingNMThread (-1312852896)
>10:31:59,919 DBG core.util: X server has signalled a successful start.
>10:32:01,137 INF display: spice-vdagent exited with status 1
>10:32:10,554 DBG installclass: Searching /usr/lib/python3.6/site-packages/pyanaconda/installclasses.
>10:32:10,782 DBG installclass: Found Atomic Host (AtomicHostInstallClass).
>10:32:10,787 DBG installclass: Found Fedora (DefaultInstallClass).
>10:32:10,792 DBG installclass: Found Fedora Workstation (FedoraWorkstationInstallClass).
>10:32:10,797 DBG installclass: Found Fedora (FedoraBaseInstallClass).
>10:32:10,802 DBG installclass: Found CentOS Linux (CentOSBaseInstallClass).
>10:32:10,807 DBG installclass: Found Scientific Linux (ScientificBaseInstallClass).
>10:32:10,812 DBG installclass: Found Red Hat Enterprise Linux (RHELBaseInstallClass).
>10:32:10,817 DBG installclass: Found Fedora Server (FedoraServerInstallClass).
>10:32:10,823 INF installclass: Using a visible install class Fedora (FedoraBaseInstallClass).
>10:32:18,787 DBG payload: getting release version from tree at None (rawhide)
>10:32:18,792 DBG payload: using default release version of rawhide
>10:32:22,742 INF bootloader: bootloader EXTLINUX on ARM platform
>10:32:22,803 INF autopart: Detected 1.08 GiB of memory
>10:32:22,824 INF autopart: Suggested swap size (2.17 GiB) exceeds 10 % of disk space, using 10 % of disk space (0.0) instead.
>10:32:22,835 INF autopart: Swap attempt of 0.0
>10:32:22,858 INF bootloader: bootloader EXTLINUX on ARM platform
>10:32:24,411 DBG storage_utils: LABEL=OEMDRV matches [] for devicetree=None and disks_only=True
>10:32:24,441 INF threading: Running Thread: AnaStorageThread (-1438460832)
>10:32:24,500 INF threading: Running Thread: AnaTimeInitThread (-1446853536)
>10:32:25,014 DBG payload: Restarting payload thread
>10:32:25,025 INF threading: Running Thread: AnaPayloadRestartThread (-1455246240)
>10:32:25,030 INF geoloc: Geolocation is enabled.10:32:25,038 INF threading: Running Thread: AnaPayloadThread (-1463638944)
>
>10:32:25,041 INF threading: Thread Done: AnaPayloadRestartThread (-1455246240)
>10:32:25,069 INF threading: Running Thread: AnaGeolocationRefreshThread (-1472031648)10:32:25,077 DBG payload: Updating payload thread state: 0
>
>10:32:25,092 INF geoloc: Starting geolocation lookup
>10:32:25,144 DBG payload: Updating payload thread state: 110:32:25,161 INF geoloc: Geolocation provider: Fedora GeoIP
>
>14:47:56,052 INF geoloc: Geolocation lookup finished in 2175330.9 seconds
>14:47:56,092 INF geoloc: got results from geolocation
>14:47:56,121 INF threading: Thread Done: AnaGeolocationRefreshThread (-1472031648)
>14:48:07,932 DBG ui.gui: Detected primary monitor: 1920x1080 96dpix 95dpiy
>14:48:19,242 DBG localization: setting locale to: en_CA.UTF-8
>14:48:19,640 DBG localization: setting locale to: en_US.UTF-8
>14:48:19,781 DBG localization: setting locale to: en_CA.UTF-8
>14:48:20,587 DBG ui.common: Entered spoke: WelcomeLanguageSpoke
>14:48:20,638 WRN misc: /usr/lib/python3.6/site-packages/gi/overrides/Gdk.py:336: DeprecationWarning: Gdk.Cursor.new is deprecated
>  return cls.new(*args, **kwds)
>
>14:48:44,275 DBG localization: setting locale to: en_CA.UTF-8
>14:48:44,370 INF ui.gui.spokes.welcome: using timezone determined by geolocation
>14:48:45,298 INF threading: Thread Done: AnaStorageThread (-1438460832)
>14:48:45,321 DBG payload: Updating payload thread state: 2
>14:48:45,329 DBG payload: Updating payload thread state: 4
>14:48:46,789 DBG ui.gui.spokes.network: network standalone spoke (init): completed: ['eth0']
>14:48:47,136 DBG ui.common: Left spoke: WelcomeLanguageSpoke
>12:56:30,026 INF threading: Thread Done: AnaTimeInitThread (-1446853536)
>12:56:30,571 DBG payload: getting release version from tree at https://kojipkgs.fedoraproject.org/compose/rawhide//Fedora-Rawhide-20180603.n.1/compose/Everything/armhfp/os/ (rawhide)
>12:56:30,578 DBG payload: retrieving treeinfo from https://kojipkgs.fedoraproject.org/compose/rawhide//Fedora-Rawhide-20180603.n.1/compose/Everything/armhfp/os/ (proxy:  ; sslverify: True)
>12:56:30,585 INF payload: Trying to download '.treeinfo'
>12:56:30,963 INF lifecycle: Adding controller: SummaryHub
>12:56:31,730 DBG payload: Retrieved '.treeinfo' from https://kojipkgs.fedoraproject.org/compose/rawhide//Fedora-Rawhide-20180603.n.1/compose/Everything/armhfp/os/
>12:56:31,758 DBG payload: using treeinfo release version of rawhide
>12:56:51,901 INF threading: Running Thread: AnaAddLayoutsInitThread (-1446853536)
>12:56:51,968 DBG ui.gui.utils: Starting applying <bound method AddLayoutDialog._addLayout of <pyanaconda.ui.gui.spokes.keyboard.AddLayoutDialog object at 0xa77c09f0>> on <list object at 0xa77b72d8>
>12:56:52,028 INF threading: Running Thread: AnaGtkBatchPre1 (-1472031648)
>12:56:52,392 INF threading: Thread Done: AnaGtkBatchPre1 (-1472031648)
>12:56:55,796 INF threading: Running Thread: AnaKeyboardThread (-1472031648)
>12:56:58,232 INF lifecycle: Module initialized: LangsupportSpoke
>12:57:06,945 INF threading: Running Thread: AnaNTPserver1 (-1438460832)
>12:57:06,966 INF threading: Running Thread: AnaDateTimeThread (-1455246240)
>12:57:08,013 INF threading: Thread Done: AnaNTPserver1 (-1438460832)
>12:57:09,851 INF threading: Running Thread: AnaSourceWatcher (-1438460832)
>12:57:10,034 DBG ui.gui.hubs: incomplete spokes: [SourceSpoke]
>12:57:10,239 INF threading: Running Thread: AnaSoftwareWatcher (-1516694432)
>12:57:10,274 DBG ui.gui.hubs: incomplete spokes: [SourceSpoke, SoftwareSelectionSpoke]
>12:57:10,923 INF threading: Running Thread: AnaStorageWatcher (-1600400288)
>12:57:10,975 INF lifecycle: Module initialized: StorageSpoke
>12:57:10,984 INF threading: Thread Done: AnaStorageWatcher (-1600400288)
>12:57:11,029 DBG ui.gui.hubs: incomplete spokes: [SourceSpoke, SoftwareSelectionSpoke, StorageSpoke]
>12:57:11,642 INF threading: Running Thread: AnaCustomStorageInit (-1600400288)
>12:57:13,430 INF lifecycle: Module initialized: BlivetGuiSpoke
>12:57:15,326 INF lifecycle: Module initialized: FilterSpoke
>12:57:17,805 DBG ui.gui.spokes.network: can't get remote connection of active connection of device eth0
>12:57:17,854 DBG ui.gui.spokes.network: device configuration added: connection 7a82f418-6e9d-48ad-8cf2-dc52cfd4abaf device eth0
>12:57:18,167 DBG ui.gui.spokes.network: not adding connection 7a82f418-6e9d-48ad-8cf2-dc52cfd4abaf, already in list
>12:57:21,563 DBG network: updating host name localhost.localdomain
>12:57:21,661 DBG payload: Updating payload thread state: 5
>12:57:24,155 INF lifecycle: Module initialized: NetworkSpoke
>12:57:25,894 INF lifecycle: Module initialized: CustomPartitioningSpoke
>12:57:25,902 INF threading: Thread Done: AnaCustomStorageInit (-1600400288)
>12:57:27,316 DBG payload: Source doesn't require network for installation
>12:57:27,341 INF lifecycle: Initialization of all modules (10) has been started.
>12:57:27,398 DBG ui.gui.hubs: Starting event loop for hub SummaryHub
>12:57:27,624 DBG ui.common: Entered hub: SummaryHub
>12:57:27,804 DBG ui.gui.hubs: spoke is not ready: KeyboardSpoke
>12:57:27,811 DBG ui.gui.hubs: setting KeyboardSpoke status to: Getting list of layouts...
>12:57:27,854 DBG ui.gui.hubs: spoke is not ready: SoftwareSelectionSpoke
>12:57:27,896 DBG ui.gui.hubs: spoke is not ready: SourceSpoke
>12:57:27,903 DBG ui.gui.hubs: setting SourceSpoke status to: Setting up installation source...
>12:57:27,910 DBG ui.gui.hubs: setting SourceSpoke status to: Probing storage...
>12:57:27,917 DBG ui.gui.hubs: setting SourceSpoke status to: Downloading package metadata...
>12:57:27,929 DBG ui.gui.hubs: setting SoftwareSelectionSpoke status to: Downloading package metadata...
>12:57:27,936 DBG ui.gui.hubs: setting StorageSpoke status to: Probing storage...
>12:57:27,943 DBG ui.gui.hubs: setting StorageSpoke status to: Probing storage...
>12:57:28,066 DBG ui.gui.hubs: spoke is ready: StorageSpoke
>12:57:28,073 DBG ui.gui.hubs: setting SourceSpoke status to: Downloading group metadata...
>12:57:28,079 DBG ui.gui.hubs: setting SoftwareSelectionSpoke status to: Downloading group metadata...
>12:57:40,025 INF lifecycle: Module initialized: DatetimeSpoke
>12:57:40,033 INF threading: Thread Done: AnaDateTimeThread (-1455246240)
>12:57:40,184 DBG ui.gui.hubs: spoke is ready: DatetimeSpoke
>12:57:58,554 DBG ui.common: Entered spoke: StorageSpoke
>12:58:56,726 WRN misc: /usr/lib/python3.6/site-packages/gi/overrides/GObject.py:553: Warning: gsignal.c:2641: instance '0x17f8df0' has no handler with id '15591'
>  return func(*args, **kwargs)
>
>12:58:56,743 WRN misc: /usr/lib/python3.6/site-packages/gi/overrides/GObject.py:553: Warning: gsignal.c:2641: instance '0x17f8df0' has no handler with id '15592'
>  return func(*args, **kwargs)
>
>12:58:57,645 INF autopart: Detected 1.08 GiB of memory
>12:58:57,658 INF autopart: Swap attempt of 2.17 GiB
>12:58:57,668 DBG ui.gui.spokes.storage: disk free: 298.09 GiB  fs free: 0 B  sw needs: 2.79 GiB  auto swap: 2.17 GiB
>12:58:57,778 INF autopart: Detected 1.08 GiB of memory
>12:58:57,796 INF autopart: Swap attempt of 2.17 GiB
>12:58:58,427 INF threading: Running Thread: AnaExecuteStorageThread (-1600400288)
>12:58:58,440 DBG ui.common: Left spoke: StorageSpoke
>12:58:59,678 DBG storage: clearpart: initializing sda
>12:59:01,857 DBG kickstart.kickstart.bootloader: Execute the bootloader with dry run True.
>12:59:02,176 DBG kickstart.kickstart.bootloader: Applying bootloader arguments: []
>12:59:02,228 DBG kickstart.kickstart.bootloader: Applying bootloader location: DEFAULT
>12:59:02,460 DBG kickstart.kickstart.bootloader: Applying drive order: []
>12:59:02,471 DBG bootloader: new disk order: []
>12:59:02,569 DBG kickstart.kickstart.bootloader: The /boot partition doesn't exist.
>12:59:02,584 DBG kickstart.kickstart.bootloader: Use the first usable drive.
>12:59:02,596 DBG kickstart.kickstart.bootloader: Using a boot drive: sda
>12:59:03,015 INF autopart: Detected 1.08 GiB of memory
>12:59:03,030 INF autopart: Swap attempt of 2.17 GiB
>12:59:03,071 DBG autopart: do_autopart: True
>12:59:03,078 DBG autopart: encrypted_autopart: True
>12:59:03,086 DBG autopart: autopart_type: 2
>12:59:03,093 DBG autopart: clear_part_type: 0
>12:59:03,100 DBG autopart: clear_part_disks: ['sda']
>12:59:03,104 DBG payload: Source doesn't require network for installation
>12:59:03,116 DBG autopart: autopart_requests:
>PartSpec instance (0xaabe0090) -- 
>  mountpoint = /  lv = True  thin = True  btrfs = True
>  weight = 0  fstype = ext4  encrypted = True
>  size = 1024 MiB  max_size = 50 GiB  grow = True
>PartSpec instance (0xaabe00f0) -- 
>  mountpoint = /home  lv = True  thin = True  btrfs = True
>  weight = 0  fstype = ext4  encrypted = True
>  size = 500 MiB  max_size = None  grow = True
>PartSpec instance (0xaabe0130) -- 
>  mountpoint = /boot  lv = False  thin = False  btrfs = False
>  weight = 0  fstype = ext4  encrypted = False
>  size = 1024 MiB  max_size = None  grow = False
>PartSpec instance (0xaabe02f0) -- 
>  mountpoint = None  lv = True  thin = False  btrfs = False
>  weight = 0  fstype = swap  encrypted = True
>  size = 2.17 GiB  max_size = None  grow = False
>
>12:59:03,134 DBG autopart: storage.disks: ['sda']
>12:59:03,160 DBG autopart: storage.partitioned: ['sda']
>12:59:03,170 DBG autopart: all names: ['/LiveOS/rootfs.img', '/overlay (deleted)', '/run/install/repo/images/install.img', 'live-base', 'live-rw', 'loop0', 'loop1', 'loop2', 'sda']
>12:59:03,178 DBG autopart: boot disk: sda
>12:59:03,332 DBG ui.gui.hubs: spoke is not ready: StorageSpoke
>12:59:03,360 DBG ui.gui.hubs: setting StorageSpoke status to: Saving storage configuration...
>12:59:03,907 DBG autopart: candidate disks: [DiskDevice instance (0xa7a29250) --
>  name = sda  status = True  id = 12
>  children = []
>  parents = []
>  uuid = None  size = 298.09 GiB
>  format = non-existent msdos disklabel
>  major = 8  minor = 0  exists = True  protected = False
>  sysfs path = /sys/devices/platform/soc@1c00000/1c18000.sata/ata1/host0/target0:0:0/0:0:0:0/block/sda
>  target size = 298.09 GiB  path = /dev/sda
>  format args = []  original_format = disklabel  removable = False  wwn = 0x5000cca6dcded407]
>12:59:03,977 DBG autopart: devs: [PartitionDevice instance (0xa76d8f50) --
>  name = req0  status = False  id = 153
>  children = []
>  parents = []
>  uuid = None  size = 500 MiB
>  format = non-existent luks
>  major = 0  minor = 0  exists = False  protected = False
>  sysfs path = 
>  target size = 500 MiB  path = /dev/req0
>  format args = []  original_format = luks  grow = True  max size = 0 B  bootable = None
>  part type = None  primary = False  start sector = None  end sector = None
>  parted_partition = None
>  disk = None
>]
>12:59:04,104 DBG bootloader: _is_valid_disklabel(sda) returning True
>12:59:04,114 DBG bootloader: _is_valid_size(sda) returning True
>12:59:04,121 DBG bootloader: _is_valid_location(sda) returning True
>12:59:04,132 DBG bootloader: _is_valid_format(sda) returning True
>12:59:04,139 DBG bootloader: is_valid_stage1_device(sda) returning True
>12:59:22,424 DBG kickstart.kickstart.bootloader: Execute the bootloader with dry run False.
>12:59:22,632 DBG kickstart.kickstart.bootloader: Applying bootloader arguments: []
>12:59:22,679 DBG kickstart.kickstart.bootloader: Applying bootloader location: DEFAULT
>12:59:22,809 DBG kickstart.kickstart.bootloader: Applying drive order: []
>12:59:22,816 DBG bootloader: new disk order: []
>12:59:22,961 DBG kickstart.kickstart.bootloader: Found a boot drive: sda
>12:59:22,968 DBG kickstart.kickstart.bootloader: Use a usable drive with a /boot partition.
>12:59:22,991 DBG kickstart.kickstart.bootloader: Using a boot drive: sda
>12:59:23,653 DBG bootloader: stage1 device cannot be of type lvmvg
>12:59:23,700 DBG bootloader: stage1 device cannot be of type lvmlv
>12:59:23,744 DBG bootloader: stage1 device cannot be of type lvmlv
>12:59:23,789 DBG bootloader: stage1 device cannot be of type lvmlv
>12:59:23,824 DBG bootloader: stage1 device cannot be of type luks/dm-crypt
>12:59:23,920 DBG bootloader: _is_valid_disklabel(sda) returning True
>12:59:23,952 DBG bootloader: _is_valid_size(sda) returning True
>12:59:23,964 DBG bootloader: _is_valid_location(sda) returning True
>12:59:23,991 DBG bootloader: _is_valid_format(sda) returning True
>12:59:24,007 DBG bootloader: is_valid_stage1_device(sda) returning True
>12:59:24,217 DBG bootloader: _is_valid_disklabel(sda) returning True
>12:59:24,226 DBG bootloader: _is_valid_size(sda) returning True
>12:59:24,248 DBG bootloader: _is_valid_location(sda) returning True
>12:59:24,264 DBG bootloader: _is_valid_format(sda) returning True
>12:59:24,288 DBG bootloader: is_valid_stage1_device(sda) returning True
>12:59:24,335 DBG bootloader: _is_valid_disklabel(sda1) returning True
>12:59:24,373 DBG bootloader: _is_valid_size(sda1) returning True
>12:59:24,407 DBG bootloader: _is_valid_location(sda1) returning True
>12:59:24,428 DBG bootloader: _is_valid_partition(sda1) returning True
>12:59:24,457 DBG bootloader: _is_valid_format(sda1) returning True
>12:59:24,477 DBG bootloader: is_valid_stage2_device(sda1) returning True
>12:59:25,368 DBG kickstart.kickstart.autopart: Storage check started with constraints {'min_ram': 410, 'min_root': Size (250 MiB), 'min_partition_sizes': {'/usr': Size (250 MiB), '/tmp': Size (50 MiB), '/var': Size (384 MiB), '/home': Size (100 MiB), '/boot': Size (200 MiB)}, 'must_be_on_linuxfs': {'/usr/lib', '/usr/share', '/', '/var', '/home', '/tmp', '/usr'}, 'must_be_on_root': {'lost+found', '/mnt', '/proc', '/bin', '/root', '/dev', '/lib', '/etc', '/sbin'}, 'swap_is_recommended': True}.
>12:59:25,375 DBG kickstart.kickstart.autopart: Run sanity check verify_root.
>12:59:25,381 DBG kickstart.kickstart.autopart: Run sanity check verify_s390_constraints.
>12:59:25,388 DBG kickstart.kickstart.autopart: Run sanity check verify_partition_sizes.
>12:59:25,409 DBG kickstart.kickstart.autopart: Run sanity check verify_partition_format_sizes.
>12:59:25,416 DBG kickstart.kickstart.autopart: Run sanity check verify_bootloader.
>12:59:25,434 DBG kickstart.kickstart.autopart: Run sanity check verify_gpt_biosboot.
>12:59:25,442 DBG kickstart.kickstart.autopart: Run sanity check verify_swap.
>12:59:25,451 DBG kickstart.kickstart.autopart: Run sanity check verify_swap_uuid.
>12:59:25,469 DBG kickstart.kickstart.autopart: Run sanity check verify_mountpoints_on_linuxfs.
>12:59:25,487 DBG kickstart.kickstart.autopart: Run sanity check verify_mountpoints_on_root.
>12:59:25,496 DBG kickstart.kickstart.autopart: Run sanity check verify_luks_devices_have_key.
>12:59:25,523 DBG kickstart.kickstart.autopart: Run sanity check verify_mounted_partitions.
>12:59:25,532 DBG kickstart.kickstart.autopart: Storage check finished with success.
>12:59:25,553 DBG kickstart.kickstart.bootloader: Execute the bootloader with dry run False.
>12:59:25,810 DBG kickstart.kickstart.bootloader: Applying bootloader arguments: []
>12:59:25,859 DBG kickstart.kickstart.bootloader: Applying bootloader location: DEFAULT
>12:59:25,961 DBG kickstart.kickstart.bootloader: Applying drive order: []
>12:59:25,973 DBG bootloader: new disk order: []
>12:59:26,149 DBG kickstart.kickstart.bootloader: Use the requested boot drive.
>12:59:29,129 DBG storage_utils: sda matches ['sda'] for devicetree=existing 298.09 GiB disk sda (12) with non-existent msdos disklabel
>  non-existent 1024 MiB partition sda1 (160) with non-existent ext4 filesystem mounted at /boot
>  non-existent 297.09 GiB partition sda2 (153) with non-existent luks
>    non-existent 297.09 GiB luks/dm-crypt luks-sda2 (167) with non-existent lvmpv
>      non-existent 297.09 GiB lvmvg fedora_bpro (173)
>        non-existent 50 GiB lvmlv fedora_bpro-root (179) with non-existent ext4 filesystem mounted at /
>        non-existent 244.91 GiB lvmlv fedora_bpro-home (188) with non-existent ext4 filesystem mounted at /home
>        non-existent 2.17 GiB lvmlv fedora_bpro-swap (197) with non-existent swap
>existing 0 B file /run/install/repo/images/install.img (22)
>  existing 0 B loop loop0 (26)
>existing 0 B file /LiveOS/rootfs.img (36)
>  existing 0 B loop loop1 (40) with existing ext4 filesystem
>    existing 2 GiB dm live-rw (59) with existing ext4 filesystem
>    existing 2 GiB dm live-base (69) with existing ext4 filesystem
>existing 0 B file /overlay (deleted) (50)
>  existing 0 B loop loop2 (54)
> and disks_only=True
>12:59:29,456 DBG kickstart.kickstart.bootloader: Using a boot drive: sda
>12:59:29,910 DBG bootloader: stage1 device cannot be of type lvmvg
>12:59:29,941 DBG bootloader: stage1 device cannot be of type lvmlv
>12:59:29,988 DBG bootloader: stage1 device cannot be of type lvmlv
>12:59:30,028 DBG bootloader: stage1 device cannot be of type lvmlv
>12:59:30,089 DBG bootloader: stage1 device cannot be of type luks/dm-crypt
>12:59:30,177 DBG bootloader: _is_valid_disklabel(sda) returning True
>12:59:30,208 DBG bootloader: _is_valid_size(sda) returning True
>12:59:30,218 DBG bootloader: _is_valid_location(sda) returning True
>12:59:30,246 DBG bootloader: _is_valid_format(sda) returning True
>12:59:30,254 DBG bootloader: is_valid_stage1_device(sda) returning True
>12:59:30,284 INF threading: Running Thread: AnaCheckStorageThread (-1455246240)
>12:59:30,875 INF threading: Thread Done: AnaExecuteStorageThread (-1600400288)
>12:59:31,113 DBG bootloader: _is_valid_disklabel(sda) returning True
>12:59:31,120 DBG bootloader: _is_valid_size(sda) returning True
>12:59:31,125 DBG bootloader: _is_valid_location(sda) returning True
>12:59:31,130 DBG bootloader: _is_valid_format(sda) returning True
>12:59:31,135 DBG bootloader: is_valid_stage1_device(sda) returning True
>12:59:31,163 DBG bootloader: _is_valid_disklabel(sda1) returning True
>12:59:31,221 DBG bootloader: _is_valid_size(sda1) returning True
>12:59:31,253 DBG bootloader: _is_valid_location(sda1) returning True
>12:59:31,261 DBG bootloader: _is_valid_partition(sda1) returning True
>12:59:31,294 DBG bootloader: _is_valid_format(sda1) returning True
>12:59:31,302 DBG bootloader: is_valid_stage2_device(sda1) returning True
>12:59:32,230 DBG ui.helpers: Storage check started with constraints {'min_ram': 410, 'min_root': Size (250 MiB), 'min_partition_sizes': {'/usr': Size (250 MiB), '/tmp': Size (50 MiB), '/var': Size (384 MiB), '/home': Size (100 MiB), '/boot': Size (200 MiB)}, 'must_be_on_linuxfs': {'/usr/lib', '/usr/share', '/', '/var', '/home', '/tmp', '/usr'}, 'must_be_on_root': {'lost+found', '/mnt', '/proc', '/bin', '/root', '/dev', '/lib', '/etc', '/sbin'}, 'swap_is_recommended': True}.
>12:59:32,236 DBG ui.helpers: Run sanity check verify_root.
>12:59:32,284 DBG ui.helpers: Run sanity check verify_s390_constraints.
>12:59:32,295 DBG ui.helpers: Run sanity check verify_partition_sizes.
>12:59:32,311 DBG ui.helpers: Run sanity check verify_partition_format_sizes.
>12:59:32,321 DBG ui.helpers: Run sanity check verify_bootloader.
>12:59:32,332 DBG ui.helpers: Run sanity check verify_gpt_biosboot.
>12:59:32,343 DBG ui.helpers: Run sanity check verify_swap.
>12:59:32,352 DBG ui.helpers: Run sanity check verify_swap_uuid.
>12:59:32,370 DBG ui.helpers: Run sanity check verify_mountpoints_on_linuxfs.
>12:59:32,375 DBG ui.helpers: Run sanity check verify_mountpoints_on_root.
>12:59:32,392 DBG ui.helpers: Run sanity check verify_luks_devices_have_key.
>12:59:32,407 DBG ui.helpers: Run sanity check verify_mounted_partitions.
>12:59:32,413 DBG ui.helpers: Storage check finished with success.
>12:59:32,428 INF threading: Thread Done: AnaCheckStorageThread (-1455246240)
>12:59:34,012 DBG ui.gui.hubs: incomplete spokes: [SourceSpoke, SoftwareSelectionSpoke]
>12:59:34,035 DBG ui.gui.hubs: spoke is ready: StorageSpoke
>12:59:34,155 DBG ui.gui.hubs: spoke is not ready: StorageSpoke
>12:59:34,166 DBG ui.gui.hubs: setting StorageSpoke status to: Checking storage configuration...
>12:59:34,287 DBG ui.gui.hubs: spoke is ready: StorageSpoke
>12:59:55,897 DBG ui.gui.utils: Finished applying <bound method AddLayoutDialog._addLayout of <pyanaconda.ui.gui.spokes.keyboard.AddLayoutDialog object at 0xa77c09f0>> on <list object at 0xa77b72d8>
>12:59:55,906 INF threading: Thread Done: AnaAddLayoutsInitThread (-1446853536)
>12:59:55,919 INF lifecycle: Module initialized: KeyboardSpoke
>12:59:55,938 INF threading: Thread Done: AnaKeyboardThread (-1472031648)
>12:59:56,084 DBG ui.gui.hubs: spoke is ready: KeyboardSpoke
>13:05:42,909 INF payload: Refreshing environmentAddons
>13:07:03,579 DBG payload: Updating payload thread state: 6
>13:07:03,588 INF ui.gui.spokes.software_selection: using environment from kickstart: None
>13:07:03,594 INF threading: Thread Done: AnaPayloadThread (-1463638944)
>13:07:03,650 DBG ui.gui.spokes.installation_source: Clearing checks in source spoke
>13:07:03,656 DBG ui.gui.spokes.installation_source: Setting up repos: []
>13:07:05,517 INF threading: Running Thread: AnaCheckSoftwareThread (-1463638944)
>13:07:05,520 INF lifecycle: Module initialized: SoftwareSelectionSpoke
>13:07:05,526 DBG ui.gui.hubs: spoke is ready: SoftwareSelectionSpoke
>13:07:05,536 INF threading: Thread Done: AnaSoftwareWatcher (-1516694432)
>13:07:05,676 DBG ui.gui.hubs: spoke is ready: SourceSpoke
>13:07:06,376 DBG payload: apply with result True called on requirements []
>13:07:06,424 DBG ui.gui.hubs: spoke is ready: SoftwareSelectionSpoke
>13:07:06,580 DBG ui.gui.hubs: spoke is not ready: SoftwareSelectionSpoke
>13:07:06,658 DBG ui.gui.hubs: spoke is not ready: SourceSpoke
>13:07:06,667 DBG ui.gui.hubs: setting SoftwareSelectionSpoke status to: Checking software dependencies...
>13:07:09,366 INF threading: Thread Done: AnaCheckSoftwareThread (-1463638944)
>13:07:09,436 DBG ui.gui.hubs: incomplete spokes: [SourceSpoke]
>13:07:09,447 DBG ui.gui.hubs: spoke is ready: SoftwareSelectionSpoke
>13:07:09,466 DBG ui.gui.hubs: incomplete spokes: []
>13:07:10,178 INF lifecycle: Module initialized: SourceSpoke
>13:07:10,198 INF lifecycle: All modules have been initialized.
>13:07:10,206 INF threading: Thread Done: AnaSourceWatcher (-1438460832)
>13:07:11,472 INF ui.lib.space: fs space: 42.5 GiB  needed: 1.18 GiB
>13:07:11,485 DBG ui.gui.hubs: spoke is ready: SourceSpoke
>13:07:13,472 INF ui.lib.space: fs space: 42.5 GiB  needed: 1.18 GiB
>13:07:13,483 DBG ui.gui.hubs: spoke is ready: SourceSpoke
>13:11:52,673 DBG ui.common: Left hub: SummaryHub
>13:11:53,326 INF lifecycle: Adding controller: ProgressHub
>13:11:53,692 INF lifecycle: Module initialized: PasswordSpoke
>13:11:53,952 DBG ui.gui.hubs: incomplete spokes: [PasswordSpoke]
>13:11:54,346 INF lifecycle: Module initialized: UserSpoke
>13:11:54,507 DBG ui.gui.hubs: incomplete spokes: [PasswordSpoke, UserSpoke]
>13:11:54,524 INF lifecycle: Initialization of all modules (2) has been started.
>13:11:54,529 INF lifecycle: All modules have been initialized.
>13:11:54,564 DBG ui.gui.hubs: Disabling event loop for hub SummaryHub
>13:11:54,571 DBG ui.gui.hubs: Starting event loop for hub ProgressHub
>13:11:54,583 INF threading: Running Thread: AnaInstallThread (-1438460832)
>13:11:54,742 INF installation: Top-level task queue: Installation queue
>Number of task queues: 9
>Number of tasks: 18
>Task & task group listing:
> Task: Save system time to HW clock
> Task queue: Installation environment setup
>  Task: Setup addons
> Task queue: Early storage configuration
>  Task: Insert custom storage to ksdata
>  Task: Run pre-storage tasks
>  Task: Activate filesystems
>  Task: Write early storage
> Task queue: Pre-install scripts
>  Task: Run %pre-install scripts
> Task queue: Realm discover
>  Task: Discover realm to join
> Task queue: Pre install tasks
>  Task: Setup authselect
>  Task: Setup firewall
>  Task: Setup network
>  Task: Setup timezone
>  Task: Copy /resolv.conf to sysroot
>  Task: Find additional packages & run preInstall()
> Task queue: Payload installation
>  Task: Install the payload
> Task queue: Late storage configuration
>  Task: Write late storage
> Task queue: Bootloader installation
>  Task: Install bootloader
> Task queue: Post-installation setup tasks
>  Task: Run post-installation setup tasks
>13:11:54,746 DBG ui.common: Entered hub: ProgressHub
>13:11:54,764 INF installation: Task started: Save system time to HW clock (1/18)
>13:11:55,406 DBG ui.gui.hubs: spoke is ready: PasswordSpoke
>13:11:55,771 DBG installation: Task completed: Save system time to HW clock (1/18) (1.0 s)
>13:11:55,784 INF progress: Save system time to HW clock
>13:11:55,802 INF progress: Setting up the installation environment
>13:11:55,812 INF installation: Queue started: Installation environment setup (1/9)
>13:11:55,824 INF installation: Task started: Setup addons (2/18)
>13:11:55,863 DBG installation: Task completed: Setup addons (2/18) (0.0 s)
>13:11:55,873 INF progress: Setup addons
>13:11:55,891 INF progress: Configuring storage
>13:11:55,901 INF installation: Queue started: Early storage configuration (2/9)
>13:11:55,912 INF installation: Task started: Insert custom storage to ksdata (3/18)
>13:11:56,625 INF storage: omitting ksdata: existing 298.09 GiB disk sda (12) with non-existent msdos disklabel
>13:11:56,826 INF storage: omitting ksdata: non-existent 297.09 GiB luks/dm-crypt luks-sda2 (167) with non-existent lvmpv
>13:11:57,059 DBG installation: Task completed: Insert custom storage to ksdata (3/18) (1.1 s)
>13:11:57,080 INF progress: Insert custom storage to ksdata
>13:11:57,096 INF installation: Task started: Run pre-storage tasks (4/18)
>13:11:57,136 DBG installation: Task completed: Run pre-storage tasks (4/18) (0.0 s)
>13:11:57,150 INF progress: Run pre-storage tasks
>13:11:57,181 INF installation: Task started: Activate filesystems (5/18)
>13:12:06,683 INF progress: Creating disklabel on /dev/sda
>13:12:17,457 INF progress: Creating ext4 on /dev/sda1
>13:12:33,125 INF progress: Creating luks on /dev/sda2
>13:12:48,937 INF progress: Creating lvmpv on /dev/mapper/luks-37a15905-8faa-4e73-8eb4-49a3766d16ff
>13:12:54,201 DBG exception: running handleException
>13:12:54,302 CRT exception: Traceback (most recent call last):
>
>  File "/usr/lib/python3.6/site-packages/gi/overrides/BlockDev.py", line 843, in wrapped
>    ret = orig_obj(*args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/gi/overrides/BlockDev.py", line 430, in lvm_pvcreate
>    return _lvm_pvcreate(device, data_alignment, metadata_size, extra)
>
>GLib.GError: g-io-error-quark: Failed to call the 'PvCreate' method on the '/com/redhat/lvmdbus1/Manager' object: Timeout was reached (24)
>
>
>During handling of the above exception, another exception occurred:
>
>
>Traceback (most recent call last):
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/threading.py", line 291, in run
>    threading.Thread.run(self)
>
>  File "/usr/lib/python3.6/threading.py", line 864, in run
>    self._target(*self._args, **self._kwargs)
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/installation.py", line 369, in doInstall
>    installation_queue.start()
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/installation_tasks.py", line 304, in start
>    item.start()
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/installation_tasks.py", line 304, in start
>    item.start()
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/installation_tasks.py", line 472, in start
>    self.run_task()
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/installation_tasks.py", line 438, in run_task
>    self._task(*self._task_args, **self._task_kwargs)
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/storage/osinstall.py", line 2142, in turn_on_filesystems
>    storage.do_it(callbacks)
>
>  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 53, in run_with_lock
>    return m(*args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/pyanaconda/storage/osinstall.py", line 1222, in do_it
>    super().do_it(callbacks=callbacks)
>
>  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 53, in run_with_lock
>    return m(*args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/blivet/blivet.py", line 135, in do_it
>    self.devicetree.actions.process(callbacks=callbacks, devices=self.devices)
>
>  File "/usr/lib/python3.6/site-packages/blivet/actionlist.py", line 48, in wrapped_func
>    return func(obj, *args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/blivet/actionlist.py", line 327, in process
>    action.execute(callbacks)
>
>  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 53, in run_with_lock
>    return m(*args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/blivet/deviceaction.py", line 616, in execute
>    options=self.device.format_args)
>
>  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 53, in run_with_lock
>    return m(*args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/blivet/formats/__init__.py", line 513, in create
>    self._create(**kwargs)
>
>  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 53, in run_with_lock
>    return m(*args, **kwargs)
>
>  File "/usr/lib/python3.6/site-packages/blivet/formats/lvmpv.py", line 125, in _create
>    blockdev.lvm.pvcreate(self.device, data_alignment=self.data_alignment)
>
>  File "/usr/lib/python3.6/site-packages/gi/overrides/BlockDev.py", line 869, in wrapped
>    raise transform[1](msg)
>
>gi.overrides.BlockDev.LVMError: Failed to call the 'PvCreate' method on the '/com/redhat/lvmdbus1/Manager' object: Timeout was reached
>
>13:12:54,376 DBG exception: Gtk running, queuing exception handler to the main loop
>13:12:54,405 INF threading: Thread Done: AnaInstallThread (-1438460832)
>13:13:57,756 INF core.util: Running kickstart %%onerror script(s)
>13:13:57,764 INF core.util: All kickstart %%onerror script(s) have been run
>13:13:57,769 INF kickstart.script: Running kickstart %%traceback script(s)
>13:13:57,775 INF kickstart.script: All kickstart %%traceback script(s) have been run

Actions: View

Attachments on bug 1586148: 1447890 | 1447891 | 1447892 | 1447893 | 1447894 | 1447895 | 1447896 | 1447897 | 1447898 | 1447899 | 1447900 | 1447901 | 1447902 | 1447903 | 1447904