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
Summary: gi.overrides.BlockDev.LVMError: Waiting for 'Activate' method of the '/com/re...
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: libblockdev
Version: 26
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Vratislav Podzimek
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:c15a87c0931026bc33e97134de9...
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-08-03 12:22 UTC by Jeff Needle
Modified: 2017-08-10 12:46 UTC (History)
12 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-08-10 12:46:28 UTC
Type: ---
Embargoed:


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


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1476548 0 unspecified CLOSED gi.overrides.BlockDev.LVMError: Failed to get properties of the /com/redhat/lvmdbus1/Pv/0 object: Timeout was reached 2021-02-22 00:41:40 UTC

Internal Links: 1476548

Description Jeff Needle 2017-08-03 12:22:40 UTC
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 12:22:48 UTC
Created attachment 1308705 [details]
File: anaconda-tb

Comment 2 Jeff Needle 2017-08-03 12:22:50 UTC
Created attachment 1308706 [details]
File: anaconda.log

Comment 3 Jeff Needle 2017-08-03 12:22:51 UTC
Created attachment 1308707 [details]
File: environ

Comment 4 Jeff Needle 2017-08-03 12:22:52 UTC
Created attachment 1308708 [details]
File: lsblk_output

Comment 5 Jeff Needle 2017-08-03 12:22:55 UTC
Created attachment 1308709 [details]
File: lvm.log

Comment 6 Jeff Needle 2017-08-03 12:22:56 UTC
Created attachment 1308710 [details]
File: nmcli_dev_list

Comment 7 Jeff Needle 2017-08-03 12:22:57 UTC
Created attachment 1308711 [details]
File: os_info

Comment 8 Jeff Needle 2017-08-03 12:22:59 UTC
Created attachment 1308712 [details]
File: storage.log

Comment 9 Jeff Needle 2017-08-03 12:23:01 UTC
Created attachment 1308713 [details]
File: syslog

Comment 10 Jeff Needle 2017-08-03 12:23:02 UTC
Created attachment 1308714 [details]
File: ifcfg.log

Comment 11 Jeff Needle 2017-08-03 12:23:04 UTC
Created attachment 1308715 [details]
File: program.log

Comment 12 Jiri Konecny 2017-08-04 08:15:37 UTC
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 12:42:44 UTC
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 12:46:28 UTC
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.