[ovirt-users] After 3.5->3.6 upgrade, OVF update error every hour
Chris Adams
cma at cmadams.net
Thu Apr 6 13:29:28 UTC 2017
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 <cma at cmadams.net>
-------------- next part --------------
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
More information about the Users
mailing list