------=_Part_16_134777541.1448296754211
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
Hello,
I'm getting the following error when I try to create a snapshot of one VM. Snapshots
of all other VMs work as expected. I'm using oVirt 3.5 on Centos 7.
Failed to create live snapshot 'fsbu3' for VM 'Odoo'.
VM restart is recommended. Note that using the created snapshot might cause data
inconsistency.
I think this is the relevant part of vdsm.log, what strikes me as odd is the line:
Thread-1192052::ERROR::2015-11-23
17:18:20,532::vm::4355::vm.Vm::(snapshot)
vmId=3D`581cebb3-7729-4c29-b98c-f9e04aa2fdd0`::The base volume doesn't exist:
{'device': 'disk', 'domainID':
'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'volumeID':
'9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7', 'imageID':
'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d'}
The part "The base volume
doesn't exist" seems interesting.
Also interesting is that it does create a snapshot, though I don't know if that
snapshot is missing data.
Thread-1192048::DEBUG::2015-11-23
17:18:20,421::taskManager::103::Storage.TaskManager::(getTaskStatus) Entry. taskID:
21a1c403-f306-40b1-bad8-377d0265ebca
Thread-1192048::DEBUG::2015-11-23
17:18:20,421::taskManager::106::Storage.TaskManager::(getTaskStatus) Return. Response:
{'code': 0, 'message': '1 jobs completed successfully',
'taskState': 'finished', 'taskResult': 'success',
'taskID': '21a1c403-f306-40b1-bad8-377d0265ebca'}
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::taskManager::123::Storage.TaskManager::(getAllTasksStatuses) Return:
{'21a1c403-f306-40b1-bad8-377d0265ebca': {'code': 0, 'message':
'1 jobs completed successfully', 'taskState': 'finished',
'taskResult': 'success', 'taskID':
'21a1c403-f306-40b1-bad8-377d0265ebca'}}
Thread-1192048::INFO::2015-11-23 17:18:20,422::logUtils::47::dispatcher::(wrapper) Run and
protect: getAllTasksStatuses, Return response: {'allTasksStatus':
{'21a1c403-f306-40b1-bad8-377d0265ebca': {'code': 0, 'message':
'1 jobs completed successfully', 'taskState': 'finished',
'taskResult': 'success', 'taskID':
'21a1c403-f306-40b1-bad8-377d0265ebca'}}}
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::task::1191::Storage.TaskManager.Task::(prepare)
Task=3D`ce3d857c-45d3-4acc-95a5-79484e457fc6`::finished: {'allTasksStatus':
{'21a1c403-f306-40b1-bad8-377d0265ebca': {'code': 0, 'message':
'1 jobs completed successfully', 'taskState': 'finished',
'taskResult': 'success', 'taskID':
'21a1c403-f306-40b1-bad8-377d0265ebca'}}}
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::task::595::Storage.TaskManager.Task::(_updateState)
Task=3D`ce3d857c-45d3-4acc-95a5-79484e457fc6`::moving from state preparing -> state
finished
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::task::993::Storage.TaskManager.Task::(_decref)
Task=3D`ce3d857c-45d3-4acc-95a5-79484e457fc6`::ref 0 aborting False
Thread-1192048::DEBUG::2015-11-23
17:18:20,422::__init__::500::jsonrpc.JsonRpcServer::(_serveRequest) Return
'Host.getAllTasksStatuses' in bridge with
{'21a1c403-f306-40b1-bad8-377d0265ebca': {'code': 0, 'message':
'1 jobs completed successfully', 'taskState': 'finished',
'taskResult': 'success', 'taskID':
'21a1c403-f306-40b1-bad8-377d0265ebca'}}
Thread-1192048::DEBUG::2015-11-23
17:18:20,423::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2015-11-23
17:18:20,423::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message
<StompFrame command=3D'SEND'>
JsonRpcServer::DEBUG::2015-11-23
17:18:20,424::__init__::506::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1192049::DEBUG::2015-11-23
17:18:20,426::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2015-11-23
17:18:20,438::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message
<StompFrame command=3D'SEND'>
JsonRpcServer::DEBUG::2015-11-23
17:18:20,439::__init__::506::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1192050::DEBUG::2015-11-23
17:18:20,441::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2015-11-23
17:18:20,442::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message
<StompFrame command=3D'SEND'>
JsonRpcServer::DEBUG::2015-11-23
17:18:20,443::__init__::506::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1192051::DEBUG::2015-11-23
17:18:20,445::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2015-11-23
17:18:20,529::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message
<StompFrame command=3D'SEND'>
Thread-1192052::DEBUG::2015-11-23
17:18:20,530::__init__::469::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'VM.snapshot' in bridge with {'vmID':
'581cebb3-7729-4c29-b98c-f9e04aa2fdd0', 'snapDrives':
[{'baseVolumeID': '9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7',
'domainID': 'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'volumeID':
'16f92498-c142-4330-bc0f-c96f210c379d', 'imageID':
'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d'}]}
JsonRpcServer::DEBUG::2015-11-23
17:18:20,530::__init__::506::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1192052::ERROR::2015-11-23 17:18:20,532::vm::4355::vm.Vm::(snapshot)
vmId=3D`581cebb3-7729-4c29-b98c-f9e04aa2fdd0`::The base volume doesn't exist:
{'device': 'disk', 'domainID':
'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'volumeID':
'9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7', 'imageID':
'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d'}
Thread-1192052::DEBUG::2015-11-23
17:18:20,532::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2015-11-23
17:18:20,588::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message
<StompFrame command=3D'SEND'>
JsonRpcServer::DEBUG::2015-11-23
17:18:20,590::__init__::506::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1192053::DEBUG::2015-11-23
17:18:20,590::__init__::469::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'Volume.getInfo' in bridge with {'imageID':
'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d', 'storagepoolID':
'00000002-0002-0002-0002-000000000354', 'volumeID':
'16f92498-c142-4330-bc0f-c96f210c379d', 'storagedomainID':
'b4e7425a-53c7-40d4-befc-ea36ed7891fc'}
Thread-1192053::DEBUG::2015-11-23
17:18:20,592::task::595::Storage.TaskManager.Task::(_updateState)
Task=3D`8f9455be-2f57-4b95-9d24-8db1522cbaed`::moving from state init -> state
preparing
Thread-1192053::INFO::2015-11-23 17:18:20,592::logUtils::44::dispatcher::(wrapper) Run and
protect: getVolumeInfo(sdUUID=3D'b4e7425a-53c7-40d4-befc-ea36ed7891fc',
spUUID=3D'00000002-0002-0002-0002-000000000354',
imgUUID=3D'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d',
volUUID=3D'16f92498-c142-4330-bc0f-c96f210c379d', options=3DNone)
Thread-1192053::DEBUG::2015-11-23
17:18:20,593::resourceManager::198::Storage.ResourceManager.Request::(__init__)
ResName=3D`Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc`ReqID=3D`e6aed3a3-c95a-4106-9a16-ad21e5db3ae7`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '3124' at
'getVolumeInfo'
Thread-1192053::DEBUG::2015-11-23
17:18:20,593::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to
register resource 'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc' for lock type
'shared'
Thread-1192053::DEBUG::2015-11-23
17:18:20,594::resourceManager::601::Storage.ResourceManager::(registerResource) Resource
'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc' is free. Now locking as
'shared' (1 active user)
Thread-1192053::DEBUG::2015-11-23
17:18:20,594::resourceManager::238::Storage.ResourceManager.Request::(grant)
ResName=3D`Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc`ReqID=3D`e6aed3a3-c95a-4106-9a16-ad21e5db3ae7`::Granted
request
Thread-1192053::DEBUG::2015-11-23
17:18:20,594::task::827::Storage.TaskManager.Task::(resourceAcquired)
Task=3D`8f9455be-2f57-4b95-9d24-8db1522cbaed`::_resourcesAcquired:
Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc (shared)
Thread-1192053::DEBUG::2015-11-23
17:18:20,594::task::993::Storage.TaskManager.Task::(_decref)
Task=3D`8f9455be-2f57-4b95-9d24-8db1522cbaed`::ref 1 aborting False
Thread-1192053::DEBUG::2015-11-23
17:18:20,594::lvm::419::Storage.OperationMutex::(_reloadlvs) Operation 'lvm reload
operation' got the operation mutex
Thread-1192053::DEBUG::2015-11-23 17:18:20,595::lvm::288::Storage.Misc.excCmd::(cmd)
/usr/bin/sudo -n /sbin/lvm lvs --config ' devices { preferred_names =3D
["^/dev/mapper/"] ignore_suspended_devices=3D1 write_cache_state=3D0
disable_after_error_count=3D3 obtain_device_list_from_udev=3D0 filter =3D [
'\''a|/dev/mapper/1p_storage_store1|'\'',
'\''r|.*|'\'' ] } global { locking_type=3D1
prioritise_write_locks=3D1 wait_for_locks=3D1 use_lvmetad=3D0 } backup { retain_min
=3D 50 retain_days =3D 0 } ' --noheadings --units b --nosuffix --separator
'|' --ignoreskippedcluster -o
uuid,name,vg_name,attr,size,seg_start_pe,devices,tags b4e7425a-53c7-40d4-befc-ea36ed7891fc
(cwd None)
Thread-1192053::DEBUG::2015-11-23 17:18:20,731::lvm::288::Storage.Misc.excCmd::(cmd)
SUCCESS: <err> =3D ''; <rc> =3D 0
Thread-1192053::DEBUG::2015-11-23 17:18:20,734::lvm::454::Storage.LVM::(_reloadlvs) lvs
reloaded
Thread-1192053::DEBUG::2015-11-23
17:18:20,734::lvm::454::Storage.OperationMutex::(_reloadlvs) Operation 'lvm reload
operation' released the operation mutex
Thread-1192053::INFO::2015-11-23 17:18:20,734::volume::847::Storage.Volume::(getInfo) Info
request: sdUUID=3Db4e7425a-53c7-40d4-befc-ea36ed7891fc
imgUUID=3Ddfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d volUUID =3D
16f92498-c142-4330-bc0f-c96f210c379d=20
Thread-1192053::DEBUG::2015-11-23
17:18:20,734::blockVolume::594::Storage.Misc.excCmd::(getMetadata) /bin/dd iflag=3Ddirect
skip=3D40 bs=3D512 if=3D/dev/b4e7425a-53c7-40d4-befc-ea36ed7891fc/metadata count=3D1 (cwd
None)
Thread-1192053::DEBUG::2015-11-23
17:18:20,745::blockVolume::594::Storage.Misc.excCmd::(getMetadata) SUCCESS: <err>
=3D '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000196717 s, 2.6
MB/s\n'; <rc> =3D 0
Thread-1192053::DEBUG::2015-11-23 17:18:20,745::misc::262::Storage.Misc::(validateDDBytes)
err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied,
0.000196717 s, 2.6 MB/s'], size: 512
Thread-1192053::INFO::2015-11-23 17:18:20,746::volume::875::Storage.Volume::(getInfo)
b4e7425a-53c7-40d4-befc-ea36ed7891fc/dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d/16f92498-c142-4330-bc0f-c96f210c379d
info is {'status': 'OK', 'domain':
'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'voltype': 'LEAF',
'description': '', 'parent':
'9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7', 'format': 'COW',
'image': 'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d', 'ctime':
'1448295499', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0', 'apparentsize':
'1073741824', 'children': [], 'pool': '',
'capacity': '21474836480', 'uuid':
'16f92498-c142-4330-bc0f-c96f210c379d', 'truesize': '1073741824',
'type': 'SPARSE'}
Thread-1192053::INFO::2015-11-23 17:18:20,746::logUtils::47::dispatcher::(wrapper) Run and
protect: getVolumeInfo, Return response: {'info': {'status': 'OK',
'domain': 'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'voltype':
'LEAF', 'description': '', 'parent':
'9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7', 'format': 'COW',
'image': 'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d', 'ctime':
'1448295499', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0', 'apparentsize':
'1073741824', 'children': [], 'pool': '',
'capacity': '21474836480', 'uuid':
'16f92498-c142-4330-bc0f-c96f210c379d', 'truesize': '1073741824',
'type': 'SPARSE'}}
Thread-1192053::DEBUG::2015-11-23
17:18:20,746::task::1191::Storage.TaskManager.Task::(prepare)
Task=3D`8f9455be-2f57-4b95-9d24-8db1522cbaed`::finished: {'info':
{'status': 'OK', 'domain':
'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'voltype': 'LEAF',
'description': '', 'parent':
'9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7', 'format': 'COW',
'image': 'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d', 'ctime':
'1448295499', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0', 'apparentsize':
'1073741824', 'children': [], 'pool': '',
'capacity': '21474836480', 'uuid':
'16f92498-c142-4330-bc0f-c96f210c379d', 'truesize': '1073741824',
'type': 'SPARSE'}}
Thread-1192053::DEBUG::2015-11-23
17:18:20,746::task::595::Storage.TaskManager.Task::(_updateState)
Task=3D`8f9455be-2f57-4b95-9d24-8db1522cbaed`::moving from state preparing -> state
finished
Thread-1192053::DEBUG::2015-11-23
17:18:20,746::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources
{'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc': < ResourceRef
'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc', isValid: 'True' obj:
'None'>}
Thread-1192053::DEBUG::2015-11-23
17:18:20,746::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-1192053::DEBUG::2015-11-23
17:18:20,747::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to
release resource 'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc'
Thread-1192053::DEBUG::2015-11-23
17:18:20,747::resourceManager::635::Storage.ResourceManager::(releaseResource) Released
resource 'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc' (0 active users)
Thread-1192053::DEBUG::2015-11-23
17:18:20,747::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource
'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc' is free, finding out if anyone is
waiting for it.
Thread-1192053::DEBUG::2015-11-23
17:18:20,747::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is
waiting for resource 'Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc', Clearing
records.
Thread-1192053::DEBUG::2015-11-23
17:18:20,747::task::993::Storage.TaskManager.Task::(_decref)
Task=3D`8f9455be-2f57-4b95-9d24-8db1522cbaed`::ref 0 aborting False
Thread-1192053::DEBUG::2015-11-23
17:18:20,748::__init__::500::jsonrpc.JsonRpcServer::(_serveRequest) Return
'Volume.getInfo' in bridge with {'status': 'OK', 'domain':
'b4e7425a-53c7-40d4-befc-ea36ed7891fc', 'voltype': 'LEAF',
'description': '', 'parent':
'9a7fc7e0-60fc-4f67-9f97-2de4bc08f0a7', 'format': 'COW',
'image': 'dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d', 'ctime':
'1448295499', 'disktype': '2', 'legality':
'LEGAL', 'allocType': 'SPARSE', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity': '21474836480', 'uuid':
'16f92498-c142-4330-bc0f-c96f210c379d', 'truesize': '1073741824',
'type': 'SPARSE'}
Thread-1192053::DEBUG::2015-11-23
17:18:20,748::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2015-11-23
17:18:20,863::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message
<StompFrame command=3D'SEND'>
JsonRpcServer::DEBUG::2015-11-23
17:18:20,864::__init__::506::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1192054::DEBUG::2015-11-23
17:18:20,864::__init__::469::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'Task.clear' in bridge with {'taskID':
'21a1c403-f306-40b1-bad8-377d0265ebca'}
------=_Part_16_134777541.1448296754211
Content-Type: application/pgp-signature; name=signature.asc
Content-Transfer-Encoding: 7bit
Content-Description: OpenPGP digital signature
Content-Disposition: attachment; filename="signature.asc"
-----BEGIN PGP SIGNATURE-----
Version: CIPHERMAIL (2.9.0-0)
iQIcBAEBCAAGBQJWU0EyAAoJEJ44dql+IcLKI0MP/3Asq2nBywx8kXJ0Gbt1wDYp
Yvakc220hhIxSKDCSuaWPoZHgBCMMi32po0lBrnyb/nq28O6vINL7EDNH5Did4fi
HIQ7JG/iyExgEwyWjhllM6d+yOIHYbIQnAqilxlnk/nBs98yXZn4LnYkaf9tDuXC
2VIYWisVM1VRkduGsIptkqN7qwfKek3NGwKBQbSL+o7CQNsCfSu7I7v7St+VyxH7
fSxRacILEaZmPSK7toSJKpZjabsmWEAbF1Finy2ni/qvnF984w/3b7Lmo0wmCbUG
2NeLveD5avQrO1RLMuSLPAO0/8aZnhPOL5ifYyM/f5WihFszmPn+72l17oMPxpwW
vpcpcsC2nq+ZTNvdR1LqYIzPlb201ohTv7YV5RJg4rU4uDfMlzv+0AEKJUlZgnmz
OLkfFH23OmmYMs6J/s/FDbsZBOZAdJpYwSdIWFyL3jfzqfoFwH0xUk6GKyZxAbRt
cMBUpDAtPoQ7qYJ+ctegY9XmexsnXhrRUTJWXTUBH7a/XKkgJbDIBLT5YRxACF33
tf1FIoc2f9RD3acdwAt/uF4wVQZI1CGZtmox0yk1dKDrPIfS3GQn6+9HZWRulT7W
han8iQLlyTN53sO4UKH8FHRjHqR0/JPmMXw4NR6r6CW6KA7Jf/m+9Bxh5sHVJXJt
kd8EaYpl165dFqUS+fy/
=fC70
-----END PGP SIGNATURE-----
------=_Part_16_134777541.1448296754211--