Bug 1477995 - gi.overrides.BlockDev.LVMError: Waiting for 'Activate' method of the '/com/redhat/lvmdbus1/Lv/2' object to finish failed: Failed to get Complete property of the /com/redhat/lvmdbus1/Job/5 object: Timeout was reached
gi.overrides.BlockDev.LVMError: Waiting for 'Activate' method of the '/com/re...
Status: CLOSED NOTABUG
Product: Fedora
Classification: Fedora
Component: libblockdev (Show other bugs)
26
x86_64 Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Vratislav Podzimek
Fedora Extras Quality Assurance
abrt_hash:c15a87c0931026bc33e97134de9...
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2017-08-03 08:22 EDT by Jeff Needle
Modified: 2017-08-10 08:46 EDT (History)
12 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2017-08-10 08:46:28 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
File: anaconda-tb (2.41 MB, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: anaconda.log (105.54 KB, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: environ (529 bytes, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: lsblk_output (3.08 KB, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: lvm.log (1.01 MB, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: nmcli_dev_list (1.71 KB, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: os_info (447 bytes, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: storage.log (781.60 KB, text/plain)
2017-08-03 08:22 EDT, Jeff Needle
no flags Details
File: syslog (304.93 KB, text/plain)
2017-08-03 08:23 EDT, Jeff Needle
no flags Details
File: ifcfg.log (1.72 KB, text/plain)
2017-08-03 08:23 EDT, Jeff Needle
no flags Details
File: program.log (151.14 KB, application/octet-stream)
2017-08-03 08:23 EDT, Jeff Needle
no flags Details

  None (edit)
Description Jeff Needle 2017-08-03 08:22:40 EDT
Description of problem:
Fresh install of F26

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

The following was filed automatically by anaconda:
anaconda 26.21.11-1 exception report
Traceback (most recent call first):
  File "/usr/lib64/python3.6/site-packages/gi/overrides/BlockDev.py", line 824, in wrapped
    raise transform[1](msg)
  File "/usr/lib/python3.6/site-packages/blivet/devices/lvm.py", line 1966, in _setup
    blockdev.lvm.lvactivate(self.vg.name, self._name)
  File "/usr/lib/python3.6/site-packages/blivet/devices/lvm.py", line 1839, in decorated
    return meth(self, *args, **kwargs)  # pylint: disable=not-callable
  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 45, in run_with_lock
    return m(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/blivet/devices/storage.py", line 377, in setup
    self._setup(orig=orig)
  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 45, in run_with_lock
    return m(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/blivet/devices/lvm.py", line 1936, in setup
    return DMDevice.setup(self, orig)
  File "/usr/lib/python3.6/site-packages/blivet/devices/lvm.py", line 1839, in decorated
    return meth(self, *args, **kwargs)  # pylint: disable=not-callable
  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 45, in run_with_lock
    return m(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/blivet/deviceaction.py", line 695, in execute
    self.device.setup(orig=True)
  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 45, in run_with_lock
    return m(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/blivet/actionlist.py", line 325, in process
    action.execute(callbacks)
  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/blivet.py", line 163, in do_it
    self.devicetree.actions.process(callbacks=callbacks, devices=self.devices)
  File "/usr/lib/python3.6/site-packages/blivet/threads.py", line 45, in run_with_lock
    return m(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/blivet/osinstall.py", line 1112, in turn_on_filesystems
    storage.do_it(callbacks)
  File "/usr/lib64/python3.6/site-packages/pyanaconda/install_tasks.py", line 437, in run_task
    self._task(*self._task_args, **self._task_kwargs)
  File "/usr/lib64/python3.6/site-packages/pyanaconda/install_tasks.py", line 471, in start
    self.run_task()
  File "/usr/lib64/python3.6/site-packages/pyanaconda/install_tasks.py", line 303, in start
    item.start()
  File "/usr/lib64/python3.6/site-packages/pyanaconda/install_tasks.py", line 303, in start
    item.start()
  File "/usr/lib64/python3.6/site-packages/pyanaconda/install.py", line 363, in doInstall
    installation_queue.start()
  File "/usr/lib64/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python3.6/site-packages/pyanaconda/threads.py", line 251, in run
    threading.Thread.run(self)
gi.overrides.BlockDev.LVMError: Waiting for 'Activate' method of the '/com/redhat/lvmdbus1/Lv/2' object to finish failed: Failed to get Complete property of the /com/redhat/lvmdbus1/Job/5 object: Timeout was reached

Additional info:
addons:         com_redhat_kdump, com_redhat_docker
cmdline:        /usr/libexec/system-python  /sbin/anaconda
cmdline_file:   initrd=/distrotrees/81749/initrd method=http://download.eng.bos.redhat.com/pub/released/F-26/GOLD/Workstation/x86_64/os/ repo=http://download.eng.bos.redhat.com/pub/released/F-26/GOLD/Workstation/x86_64/os/  BOOT_IMAGE=/distrotrees/81749/kernel 
executable:     /sbin/anaconda
hashmarkername: anaconda
kernel:         4.11.8-300.fc26.x86_64
product:        Fedora
release:        Cannot get release name.
type:           anaconda
version:        26
Comment 1 Jeff Needle 2017-08-03 08:22:48 EDT
Created attachment 1308705 [details]
File: anaconda-tb
Comment 2 Jeff Needle 2017-08-03 08:22:50 EDT
Created attachment 1308706 [details]
File: anaconda.log
Comment 3 Jeff Needle 2017-08-03 08:22:51 EDT
Created attachment 1308707 [details]
File: environ
Comment 4 Jeff Needle 2017-08-03 08:22:52 EDT
Created attachment 1308708 [details]
File: lsblk_output
Comment 5 Jeff Needle 2017-08-03 08:22:55 EDT
Created attachment 1308709 [details]
File: lvm.log
Comment 6 Jeff Needle 2017-08-03 08:22:56 EDT
Created attachment 1308710 [details]
File: nmcli_dev_list
Comment 7 Jeff Needle 2017-08-03 08:22:57 EDT
Created attachment 1308711 [details]
File: os_info
Comment 8 Jeff Needle 2017-08-03 08:22:59 EDT
Created attachment 1308712 [details]
File: storage.log
Comment 9 Jeff Needle 2017-08-03 08:23:01 EDT
Created attachment 1308713 [details]
File: syslog
Comment 10 Jeff Needle 2017-08-03 08:23:02 EDT
Created attachment 1308714 [details]
File: ifcfg.log
Comment 11 Jeff Needle 2017-08-03 08:23:04 EDT
Created attachment 1308715 [details]
File: program.log
Comment 12 Jiri Konecny 2017-08-04 04:15:37 EDT
This looks like a bug in storage. Could be problem in LVM or libraries calling LVM.

Changing component.
Comment 13 Marian Csontos 2017-08-10 08:42:44 EDT
There were no changes in lvm2 recently on f26.

Anyway I am not sure LVM or Anaconda is to blame, the syslog is full of Medium Error's:

12:17:20,528 INFO kernel:sd 4:0:2:0: [sdc] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
12:17:20,529 INFO kernel:sd 4:0:2:0: [sdc] tag#0 Sense Key : Medium Error [current] 
12:17:20,529 INFO kernel:sd 4:0:2:0: [sdc] tag#0 Add. Sense: Unrecovered read error
12:17:20,530 INFO kernel:sd 4:0:2:0: [sdc] tag#0 CDB: Read(10) 28 00 00 00 00 00 00 00 08 00
12:17:20,531 ERR kernel:blk_update_request: critical medium error, dev sdc, sector 0
12:17:51,653 INFO kernel:mptscsih: ioc0: attempting task abort! (sc=ffff999991025148)
12:17:51,653 INFO kernel:sd 4:0:2:0: [sdc] tag#0 CDB: Read(10) 28 00 00 00 00 00 00 00 08 00
12:17:51,689 INFO kernel:mptbase: ioc0: LogInfo(0x31110700): Originator={PL}, Code={Reset}, SubCode(0x0700) cb_idx mptbase_reply
12:17:52,152 INFO kernel:mptbase: ioc0: LogInfo(0x31140000): Originator={PL}, Code={IO Executed}, SubCode(0x0000) cb_idx mptscsih_io_done
12:17:52,152 INFO kernel:mptscsih: ioc0: task abort: SUCCESS (rv=2002) (sc=ffff999991025148)
12:17:56,305 INFO kernel:sd 4:0:2:0: [sdc] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
12:17:56,306 INFO kernel:sd 4:0:2:0: [sdc] tag#0 Sense Key : Medium Error [current] 
12:17:56,307 INFO kernel:sd 4:0:2:0: [sdc] tag#0 Add. Sense: Unrecovered read error
12:17:56,307 INFO kernel:sd 4:0:2:0: [sdc] tag#0 CDB: Read(10) 28 00 00 00 00 00 00 00 08 00
12:17:56,308 ERR kernel:blk_update_request: critical medium error, dev sdc, sector 0
12:17:56,308 ERR kernel:Buffer I/O error on dev sdc, logical block 0, async page read

...and on and on. Check the disk.

Is it multipath?

12:18:37,156 NOTICE multipathd:dm-2: remove map (uevent)
12:18:37,157 NOTICE multipathd:dm-2: devmap not registered, can't remove
12:18:37,159 NOTICE multipathd:dm-2: remove map (uevent)

May be path was not recognized, but it should be still possible to read/write to legs IIUC.

Does it work with F25?
Comment 14 Jeff Needle 2017-08-10 08:46:28 EDT
It's fairly likely that this was due to bad disks.  Sorry, meant to go back and close this after I installed to another disk and saw a stream of bad blocks.

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