[ovirt-users] Failed to create live snapshot
mots
mots at nepu.moe
Mon Nov 23 16:39:11 UTC 2015
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=`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=`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=`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=`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='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='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='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='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=`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='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=`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='b4e7425a-53c7-40d4-befc-ea36ed7891fc', spUUID='00000002-0002-0002-0002-000000000354', imgUUID='dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d', volUUID='16f92498-c142-4330-bc0f-c96f210c379d', options=None)
Thread-1192053::DEBUG::2015-11-23 17:18:20,593::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc`ReqID=`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=`Storage.b4e7425a-53c7-40d4-befc-ea36ed7891fc`ReqID=`e6aed3a3-c95a-4106-9a16-ad21e5db3ae7`::Granted request
Thread-1192053::DEBUG::2015-11-23 17:18:20,594::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=`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=`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 = ["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 obtain_device_list_from_udev=0 filter = [ '\''a|/dev/mapper/1p_storage_store1|'\'', '\''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 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> = ''; <rc> = 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=b4e7425a-53c7-40d4-befc-ea36ed7891fc imgUUID=dfa1d0bf-a1f6-45bb-9574-ab020c0e8c9d volUUID = 16f92498-c142-4330-bc0f-c96f210c379d
Thread-1192053::DEBUG::2015-11-23 17:18:20,734::blockVolume::594::Storage.Misc.excCmd::(getMetadata) /bin/dd iflag=direct skip=40 bs=512 if=/dev/b4e7425a-53c7-40d4-befc-ea36ed7891fc/metadata count=1 (cwd None)
Thread-1192053::DEBUG::2015-11-23 17:18:20,745::blockVolume::594::Storage.Misc.excCmd::(getMetadata) SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000196717 s, 2.6 MB/s\n'; <rc> = 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=`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=`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=`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='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'}
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 831 bytes
Desc: OpenPGP digital signature
URL: <http://lists.ovirt.org/pipermail/users/attachments/20151123/dea6c1ba/attachment-0001.sig>
More information about the Users
mailing list