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'}
signature.asc
Description: OpenPGP digital signature
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
