After upgrading an oVirt cluster from 3.5 to 3.6, I am getting the
following error every hour:
Failed to update OVF disks ce8647c6-f936-4633-8a7b-e7dcb45d8ebb, OVF
data isn't updated on those OVF stores (Data Center Middle-Earth,
Storage Domain equallogic).
Looking in the vdsm log on the SPM node, it looks like the problem is
that an attempt was made to lvextend an LV to 2m, but the LV is already
128m, so the extend failed (not needed). I've attached the log entries
for that task.
Any suggestions, ideas how to fix, etc.?
--
Chris Adams <c...@cmadams.net>
Thread-735868::DEBUG::2017-04-06
08:12:26,651::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state init -> state
preparing
Thread-735868::DEBUG::2017-04-06
08:12:26,673::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
Thread-735868::DEBUG::2017-04-06
08:12:26,678::taskManager::78::Storage.TaskManager::(scheduleJob) scheduled job
downloadImageFromStream for task c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
Thread-735868::DEBUG::2017-04-06
08:12:26,678::task::1183::Storage.TaskManager.Task::(prepare)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Prepare: 1 jobs exist, move to
acquiring
Thread-735868::DEBUG::2017-04-06
08:12:26,679::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state preparing ->
state acquiring
Thread-735868::DEBUG::2017-04-06
08:12:26,680::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
Thread-735868::DEBUG::2017-04-06
08:12:26,686::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state acquiring ->
state queued
Thread-735868::DEBUG::2017-04-06
08:12:26,686::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
Thread-735868::DEBUG::2017-04-06
08:12:26,693::taskManager::56::Storage.TaskManager::(_queueTask) queuing task:
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,693::threadPool::194::Storage.ThreadPool.WorkerThread::(_processNextTask)
Task: c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac running: <bound method Task.commit
of <storage.task.Task instance at 0x7f6ba0827908>> with: None
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,693::task::1200::Storage.TaskManager.Task::(commit)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::committing task:
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,694::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state queued -> state
running
Thread-735868::DEBUG::2017-04-06
08:12:26,694::taskManager::64::Storage.TaskManager::(_queueTask) task queued:
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
Thread-735868::DEBUG::2017-04-06
08:12:26,694::task::1188::Storage.TaskManager.Task::(prepare)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::returning
Thread-735868::DEBUG::2017-04-06
08:12:26,694::task::993::Storage.TaskManager.Task::(_decref)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::ref 1 aborting False
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,695::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,701::task::905::Storage.TaskManager.Task::(_runJobs)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Task.run: running job 0:
downloadImageFromStream: <bound method StoragePool.downloadImageFromStream of
<storage.sp.StoragePool object at 0x7f6bac4bf090>> (args: ({'length': 1136640,
'fileObj': <socket._fileobject object at 0x7f6ba0619bd0>}, <function
setCallback at 0x7f6bc05eb938>, '2c2e3b6c-7161-45c5-ae80-3639ab565961',
'ce8647c6-f936-4633-8a7b-e7dcb45d8ebb', '96be6a82-ab6a-4e38-b184-6dc65e57847c')
kwargs: {})
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,702::task::329::Storage.TaskManager.Task::(run)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Job.run: running
downloadImageFromStream: <bound method StoragePool.downloadImageFromStream of
<storage.sp.StoragePool object at 0x7f6bac4bf090>> (args: ({'length': 1136640,
'fileObj': <socket._fileobject object at 0x7f6ba0619bd0>}, <function
setCallback at 0x7f6bc05eb938>, '2c2e3b6c-7161-45c5-ae80-3639ab565961',
'ce8647c6-f936-4633-8a7b-e7dcb45d8ebb', '96be6a82-ab6a-4e38-b184-6dc65e57847c')
kwargs: {}) callback None
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,702::resourceManager::199::Storage.ResourceManager.Request::(__init__)
ResName=`2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb`ReqID=`37746d73-091b-4286-9b5d-2a539dbfc8c7`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '1771' at
'downloadImageFromStream'
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,702::resourceManager::545::Storage.ResourceManager::(registerResource)
Trying to register resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb'
for lock type 'exclusive'
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,703::lvm::427::Storage.OperationMutex::(_reloadlvs) Operation 'lvm
reload operation' got the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,703::lvm::290::Storage.Misc.excCmd::(cmd) /usr/bin/taskset --cpu-list
0-15 /usr/bin/sudo -n /usr/sbin/lvm lvs --config ' devices { preferred_names =
["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0
disable_after_error_count=3 filter = [
'\''a|/dev/mapper/36861a6ed9669ad1b4983b59b936d4d13|'\'', '\''r|.*|'\'' ] }
global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1
use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 } ' --noheadings
--units b --nosuffix --separator '|' --ignoreskippedcluster -o
uuid,name,vg_name,attr,size,seg_start_pe,devices,tags
2c2e3b6c-7161-45c5-ae80-3639ab565961 (cwd None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,789::lvm::290::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' WARNING:
Not using lvmetad because config setting use_lvmetad=0.\n WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan --cache).\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,794::lvm::462::Storage.LVM::(_reloadlvs) lvs reloaded
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,795::lvm::462::Storage.OperationMutex::(_reloadlvs) Operation 'lvm
reload operation' released the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,795::blockVolume::631::Storage.Misc.excCmd::(getMetadata)
/usr/bin/taskset --cpu-list 0-15 /usr/bin/dd iflag=direct skip=5 bs=512
if=/dev/2c2e3b6c-7161-45c5-ae80-3639ab565961/metadata count=1 (cwd None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,823::blockVolume::631::Storage.Misc.excCmd::(getMetadata) SUCCESS:
<err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.00651756
s, 78.6 kB/s\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,823::misc::261::Storage.Misc::(validateDDBytes) err: ['1+0 records
in', '1+0 records out', '512 bytes (512 B) copied, 0.00651756 s, 78.6 kB/s'],
size: 512
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,824::blockVolume::631::Storage.Misc.excCmd::(getMetadata)
/usr/bin/taskset --cpu-list 0-15 /usr/bin/dd iflag=direct skip=5 bs=512
if=/dev/2c2e3b6c-7161-45c5-ae80-3639ab565961/metadata count=1 (cwd None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,855::blockVolume::631::Storage.Misc.excCmd::(getMetadata) SUCCESS:
<err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.00649076
s, 78.9 kB/s\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,856::misc::261::Storage.Misc::(validateDDBytes) err: ['1+0 records
in', '1+0 records out', '512 bytes (512 B) copied, 0.00649076 s, 78.9 kB/s'],
size: 512
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::INFO::2017-04-06
08:12:26,856::image::228::Storage.Image::(getChain)
sdUUID=2c2e3b6c-7161-45c5-ae80-3639ab565961
imgUUID=ce8647c6-f936-4633-8a7b-e7dcb45d8ebb
chain=[<storage.blockVolume.BlockVolume object at 0x7f6b7009bc10>]
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,857::resourceManager::199::Storage.ResourceManager.Request::(__init__)
ResName=`2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c`ReqID=`6a054f68-66b7-4b24-bb76-a75558b8a339`::Request
was made in '/usr/share/vdsm/storage/resourceFactories.py' line '172' at
'__getResourceCandidatesList'
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,857::resourceManager::545::Storage.ResourceManager::(registerResource)
Trying to register resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c'
for lock type 'exclusive'
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,857::resourceManager::604::Storage.ResourceManager::(registerResource)
Resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c'
is free. Now locking as 'exclusive' (1 active user)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,857::resourceManager::239::Storage.ResourceManager.Request::(grant)
ResName=`2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c`ReqID=`6a054f68-66b7-4b24-bb76-a75558b8a339`::Granted
request
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,858::resourceManager::604::Storage.ResourceManager::(registerResource)
Resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb'
is free. Now locking as 'exclusive' (1 active user)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,858::resourceManager::239::Storage.ResourceManager.Request::(grant)
ResName=`2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb`ReqID=`37746d73-091b-4286-9b5d-2a539dbfc8c7`::Granted
request
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,858::blockVolume::631::Storage.Misc.excCmd::(getMetadata)
/usr/bin/taskset --cpu-list 0-15 /usr/bin/dd iflag=direct skip=5 bs=512
if=/dev/2c2e3b6c-7161-45c5-ae80-3639ab565961/metadata count=1 (cwd None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,882::blockVolume::631::Storage.Misc.excCmd::(getMetadata) SUCCESS:
<err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.00641695
s, 79.8 kB/s\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,882::misc::261::Storage.Misc::(validateDDBytes) err: ['1+0 records
in', '1+0 records out', '512 bytes (512 B) copied, 0.00641695 s, 79.8 kB/s'],
size: 512
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::INFO::2017-04-06
08:12:26,883::image::228::Storage.Image::(getChain)
sdUUID=2c2e3b6c-7161-45c5-ae80-3639ab565961
imgUUID=ce8647c6-f936-4633-8a7b-e7dcb45d8ebb
chain=[<storage.blockVolume.BlockVolume object at 0x7f6b7009b850>]
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:26,883::lvm::290::Storage.Misc.excCmd::(cmd) /usr/bin/taskset --cpu-list
0-15 /usr/bin/sudo -n /usr/sbin/lvm lvchange --config ' devices {
preferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1
write_cache_state=0 disable_after_error_count=3 filter = [
'\''a|/dev/mapper/36861a6ed9669ad1b4983b59b936d4d13|'\'', '\''r|.*|'\'' ] }
global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1
use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 } ' --autobackup n
--available y
2c2e3b6c-7161-45c5-ae80-3639ab565961/96be6a82-ab6a-4e38-b184-6dc65e57847c (cwd
None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,092::lvm::290::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' WARNING:
Not using lvmetad because config setting use_lvmetad=0.\n WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan --cache).\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,092::lvm::513::Storage.OperationMutex::(_invalidatelvs) Operation 'lvm
invalidate operation' got the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,092::lvm::525::Storage.OperationMutex::(_invalidatelvs) Operation 'lvm
invalidate operation' released the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,093::fileUtils::143::Storage.fileUtils::(createdir) Creating
directory:
/var/run/vdsm/storage/2c2e3b6c-7161-45c5-ae80-3639ab565961/ce8647c6-f936-4633-8a7b-e7dcb45d8ebb
mode: None
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,093::blockSD::1108::Storage.StorageDomain::(createImageLinks) Creating
symlink from
/dev/2c2e3b6c-7161-45c5-ae80-3639ab565961/96be6a82-ab6a-4e38-b184-6dc65e57847c
to
/var/run/vdsm/storage/2c2e3b6c-7161-45c5-ae80-3639ab565961/ce8647c6-f936-4633-8a7b-e7dcb45d8ebb/96be6a82-ab6a-4e38-b184-6dc65e57847c
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::INFO::2017-04-06
08:12:27,093::blockVolume::306::Storage.Volume::(extend) Request to extend LV
96be6a82-ab6a-4e38-b184-6dc65e57847c of image
ce8647c6-f936-4633-8a7b-e7dcb45d8ebb in VG 2c2e3b6c-7161-45c5-ae80-3639ab565961
with size = 2220
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,094::lvm::290::Storage.Misc.excCmd::(cmd) /usr/bin/taskset --cpu-list
0-15 /usr/bin/sudo -n /usr/sbin/lvm lvextend --config ' devices {
preferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1
write_cache_state=0 disable_after_error_count=3 filter = [
'\''a|/dev/mapper/36861a6ed9669ad1b4983b59b936d4d13|'\'', '\''r|.*|'\'' ] }
global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1
use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 } ' --autobackup n
--size 2m
2c2e3b6c-7161-45c5-ae80-3639ab565961/96be6a82-ab6a-4e38-b184-6dc65e57847c (cwd
None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,168::lvm::290::Storage.Misc.excCmd::(cmd) FAILED: <err> = ' WARNING:
Not using lvmetad because config setting use_lvmetad=0.\n WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan --cache).\n New
size (1 extents) matches existing size (1 extents).\n'; <rc> = 5
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,177::lvm::300::Storage.Misc.excCmd::(cmd) /usr/bin/taskset --cpu-list
0-15 /usr/bin/sudo -n /usr/sbin/lvm lvextend --config ' devices {
preferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1
write_cache_state=0 disable_after_error_count=3 filter = [
'\''a|/dev/mapper/36861a6ed96692d44e282359b936dadeb|/dev/mapper/36861a6ed9669ad1b4983b59b936d4d13|'\'',
'\''r|.*|'\'' ] } global { locking_type=1 prioritise_write_locks=1
wait_for_locks=1 use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 }
' --autobackup n --size 2m
2c2e3b6c-7161-45c5-ae80-3639ab565961/96be6a82-ab6a-4e38-b184-6dc65e57847c (cwd
None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,267::lvm::300::Storage.Misc.excCmd::(cmd) FAILED: <err> = ' WARNING:
Not using lvmetad because config setting use_lvmetad=0.\n WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan --cache).\n New
size (1 extents) matches existing size (1 extents).\n'; <rc> = 5
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,267::fileUtils::124::Storage.fileUtils::(cleanupdir) Removing
directory:
/var/run/vdsm/storage/2c2e3b6c-7161-45c5-ae80-3639ab565961/ce8647c6-f936-4633-8a7b-e7dcb45d8ebb
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,268::lvm::427::Storage.OperationMutex::(_reloadlvs) Operation 'lvm
reload operation' got the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,268::lvm::290::Storage.Misc.excCmd::(cmd) /usr/bin/taskset --cpu-list
0-15 /usr/bin/sudo -n /usr/sbin/lvm lvs --config ' devices { preferred_names =
["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0
disable_after_error_count=3 filter = [
'\''a|/dev/mapper/36861a6ed9669ad1b4983b59b936d4d13|'\'', '\''r|.*|'\'' ] }
global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1
use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 } ' --noheadings
--units b --nosuffix --separator '|' --ignoreskippedcluster -o
uuid,name,vg_name,attr,size,seg_start_pe,devices,tags
2c2e3b6c-7161-45c5-ae80-3639ab565961 (cwd None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,353::lvm::290::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' WARNING:
Not using lvmetad because config setting use_lvmetad=0.\n WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan --cache).\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,358::lvm::462::Storage.LVM::(_reloadlvs) lvs reloaded
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,358::lvm::462::Storage.OperationMutex::(_reloadlvs) Operation 'lvm
reload operation' released the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,362::lvm::290::Storage.Misc.excCmd::(cmd) /usr/bin/taskset --cpu-list
0-15 /usr/bin/sudo -n /usr/sbin/lvm lvchange --config ' devices {
preferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1
write_cache_state=0 disable_after_error_count=3 filter = [
'\''a|/dev/mapper/36861a6ed9669ad1b4983b59b936d4d13|'\'', '\''r|.*|'\'' ] }
global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1
use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 } ' --autobackup n
--available n
2c2e3b6c-7161-45c5-ae80-3639ab565961/96be6a82-ab6a-4e38-b184-6dc65e57847c (cwd
None)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,455::lvm::290::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' WARNING:
Not using lvmetad because config setting use_lvmetad=0.\n WARNING: To avoid
corruption, rescan devices to make changes visible (pvscan --cache).\n'; <rc> = 0
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,456::lvm::513::Storage.OperationMutex::(_invalidatelvs) Operation 'lvm
invalidate operation' got the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,456::lvm::525::Storage.OperationMutex::(_invalidatelvs) Operation 'lvm
invalidate operation' released the operation mutex
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,456::resourceManager::619::Storage.ResourceManager::(releaseResource)
Trying to release resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb'
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,457::resourceManager::638::Storage.ResourceManager::(releaseResource)
Released resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb'
(0 active users)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,457::resourceManager::644::Storage.ResourceManager::(releaseResource)
Resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb'
is free, finding out if anyone is waiting for it.
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,457::resourceManager::619::Storage.ResourceManager::(releaseResource)
Trying to release resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c'
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,457::resourceManager::638::Storage.ResourceManager::(releaseResource)
Released resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c'
(0 active users)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,458::resourceManager::644::Storage.ResourceManager::(releaseResource)
Resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c'
is free, finding out if anyone is waiting for it.
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,458::resourceManager::652::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_volumeNS.96be6a82-ab6a-4e38-b184-6dc65e57847c',
Clearing records.
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,458::resourceManager::652::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'2c2e3b6c-7161-45c5-ae80-3639ab565961_imageNS.ce8647c6-f936-4633-8a7b-e7dcb45d8ebb',
Clearing records.
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::ERROR::2017-04-06
08:12:27,458::task::866::Storage.TaskManager.Task::(_setError)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Unexpected error
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,459::task::885::Storage.TaskManager.Task::(_run)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Task._run:
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac () {} failed - stopping task
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,459::task::1246::Storage.TaskManager.Task::(stop)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::stopping in state running (force
False)
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,459::task::993::Storage.TaskManager.Task::(_decref)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::ref 1 aborting True
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,459::task::919::Storage.TaskManager.Task::(_runJobs)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::aborting: Task is aborted:
'Logical Volume extend failed' - code 554
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,459::task::993::Storage.TaskManager.Task::(_decref)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::ref 0 aborting True
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,460::task::928::Storage.TaskManager.Task::(_doAbort)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Task._doAbort: force False
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,460::resourceManager::980::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,460::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state running -> state
aborting
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,462::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,470::task::550::Storage.TaskManager.Task::(__state_aborting)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_aborting: recover policy auto
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,470::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state aborting ->
state racquiring
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,470::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,477::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state racquiring ->
state recovering
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,478::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,485::task::798::Storage.TaskManager.Task::(_recover)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_recover
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,485::task::805::Storage.TaskManager.Task::(_recover)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::running recovery None
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,485::task::786::Storage.TaskManager.Task::(_recoverDone)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::Recover Done: state recovering
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,485::task::595::Storage.TaskManager.Task::(_updateState)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::moving from state recovering ->
state recovered
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,486::task::752::Storage.TaskManager.Task::(_save)
Task=`c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac`::_save: orig
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac
temp
/rhev/data-center/00000002-0002-0002-0002-000000000336/mastersd/master/tasks/c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac.temp
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,493::resourceManager::943::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,493::resourceManager::980::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
c08b90ca-32dd-4c88-9f5c-7b2be5bf66ac::DEBUG::2017-04-06
08:12:27,493::threadPool::51::Storage.ThreadPool::(setRunningTask) Number of
running tasks: 0
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
