<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN">
<html><body>
<p>Sorry but i have not GlusterVolume.list snippet in my vdsm.log, i have GlusterVolume.status snippet. Here it is :</p>
<p>Thread-41026::DEBUG::2015-11-24 10:05:44,051::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'GlusterVolume.status' in bridge with {u'volumeName': u'engine', u'brick': u'', u'statusOption': u''}<br />Thread-41026::DEBUG::2015-11-24 10:05:44,167::__init__::533::jsonrpc.JsonRpcServer::(_serveRequest) Return 'GlusterVolume.status' in bridge with {'volumeStatus': {'bricks': [{'status': 'ONLINE', 'hostuuid': '56f<br />33ccc-643b-4f6e-9e65-1d8aea25cea9', 'pid': '2604', 'rdma_port': 'N/A', 'brick': 'ovirt01.mafia.kru:/gfs1/engine/brick', 'port': '49152'}, {'status': 'ONLINE', 'hostuuid': '517a42f9-89ba-4b0c-90ee-5daf728f1515', <br />'pid': '2525', 'rdma_port': 'N/A', 'brick': 'ovirt02.mafia.kru:/gfs1/engine/brick', 'port': '49152'}, {'status': 'ONLINE', 'hostuuid': '38cec23d-c46b-48dd-95f5-fc060c8f4e2c', 'pid': '4091', 'rdma_port': 'N/A', '<br />brick': 'ovirt03.mafia.kru:/gfs1/engine/brick', 'port': '49152'}, {'status': 'ONLINE', 'hostuuid': '56f33ccc-643b-4f6e-9e65-1d8aea25cea9', 'pid': '2605', 'rdma_port': 'N/A', 'brick': 'ovirt01.mafia.kru:/gfs2/eng<br />ine/brick', 'port': '49153'}, {'status': 'ONLINE', 'hostuuid': '517a42f9-89ba-4b0c-90ee-5daf728f1515', 'pid': '2533', 'rdma_port': 'N/A', 'brick': 'ovirt02.mafia.kru:/gfs2/engine/brick', 'port': '49153'}, {'stat<br />us': 'ONLINE', 'hostuuid': '38cec23d-c46b-48dd-95f5-fc060c8f4e2c', 'pid': '4104', 'rdma_port': 'N/A', 'brick': 'ovirt03.mafia.kru:/gfs2/engine/brick', 'port': '49153'}], 'nfs': [{'status': 'ONLINE', 'hostuuid': <br />'56f33ccc-643b-4f6e-9e65-1d8aea25cea9', 'hostname': '10.10.10.211/24', 'pid': '2642', 'rdma_port': 'N/A', 'port': '2049'}, {'status': 'ONLINE', 'hostuuid': '38cec23d-c46b-48dd-95f5-fc060c8f4e2c', 'hostname': 'ov<br />irt03.mafia.kru', 'pid': '4141', 'rdma_port': 'N/A', 'port': '2049'}, {'status': 'ONLINE', 'hostuuid': '517a42f9-89ba-4b0c-90ee-5daf728f1515', 'hostname': 'ovirt02.mafia.kru', 'pid': '2574', 'rdma_port': 'N/A', <br />'port': '2049'}], 'shd': [{'status': 'ONLINE', 'hostname': '10.10.10.211/24', 'pid': '2651', 'hostuuid': '56f33ccc-643b-4f6e-9e65-1d8aea25cea9'}, {'status': 'ONLINE', 'hostname': 'ovirt03.mafia.kru', 'pid': '414<br />6', 'hostuuid': '38cec23d-c46b-48dd-95f5-fc060c8f4e2c'}, {'status': 'ONLINE', 'hostname': 'ovirt02.mafia.kru', 'pid': '2576', 'hostuuid': '517a42f9-89ba-4b0c-90ee-5daf728f1515'}], 'name': 'engine'}}<br />Thread-41027::DEBUG::2015-11-24 10:05:44,201::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'GlusterVolume.status' in bridge with {u'volumeName': u'engine', u'brick': u'', u'statusOption': u'deta<br />il'}<br />Thread-41027::DEBUG::2015-11-24 10:05:45,463::__init__::533::jsonrpc.JsonRpcServer::(_serveRequest) Return 'GlusterVolume.status' in bridge with {'volumeStatus': {'bricks': [{'hostuuid': '56f33ccc-643b-4f6e-9e65<br />-1d8aea25cea9', 'blockSize': '4096', 'sizeFree': '75418.355', 'sizeTotal': '102350.000', 'mntOptions': 'rw,relatime,attr2,inode64,noquota', 'device': '/dev/mapper/data-gfs1', 'brick': 'ovirt01.mafia.kru:/gfs1/en<br />gine/brick', 'fsName': 'xfs'}, {'hostuuid': '517a42f9-89ba-4b0c-90ee-5daf728f1515', 'blockSize': '4096', 'sizeFree': '75418.363', 'sizeTotal': '102350.000', 'mntOptions': 'rw,relatime,attr2,inode64,noquota', 'de<br />vice': '/dev/mapper/data-gfs1', 'brick': 'ovirt02.mafia.kru:/gfs1/engine/brick', 'fsName': 'xfs'}, {'hostuuid': '38cec23d-c46b-48dd-95f5-fc060c8f4e2c', 'blockSize': '4096', 'sizeFree': '75418.348', 'sizeTotal': <br />'102350.000', 'mntOptions': 'rw,relatime,attr2,inode64,noquota', 'device': '/dev/mapper/data-gfs1', 'brick': 'ovirt03.mafia.kru:/gfs1/engine/brick', 'fsName': 'xfs'}, {'hostuuid': '56f33ccc-643b-4f6e-9e65-1d8aea<br />25cea9', 'blockSize': '4096', 'sizeFree': '69881.926', 'sizeTotal': '102350.000', 'mntOptions': 'rw,relatime,attr2,inode64,noquota', 'device': '/dev/mapper/data-gfs2', 'brick': 'ovirt01.mafia.kru:/gfs2/engine/br<br />ick', 'fsName': 'xfs'}, {'hostuuid': '517a42f9-89ba-4b0c-90ee-5daf728f1515', 'blockSize': '4096', 'sizeFree': '69881.906', 'sizeTotal': '102350.000', 'mntOptions': 'rw,relatime,attr2,inode64,noquota', 'device': <br />'/dev/mapper/data-gfs2', 'brick': 'ovirt02.mafia.kru:/gfs2/engine/brick', 'fsName': 'xfs'}, {'hostuuid': '38cec23d-c46b-48dd-95f5-fc060c8f4e2c', 'blockSize': '4096', 'sizeFree': '69881.996', 'sizeTotal': '102350<br />.000', 'mntOptions': 'rw,relatime,attr2,inode64,noquota', 'device': '/dev/mapper/data-gfs2', 'brick': 'ovirt03.mafia.kru:/gfs2/engine/brick', 'fsName': 'xfs'}], 'volumeStatsInfo': {'sizeTotal': '214643507200', '<br />sizeUsed': '62285148160', 'sizeFree': '152358359040'}, 'name': 'engine'}}</p>
<p> </p>
<div>Cordialement,<br />
<p>Florent BELLO<br />Service Informatique<br />informatique@ville-kourou.fr<br />0594 22 31 22<br />Mairie de Kourou</p>
</div>
<p>Le 18/11/2015 13:11, Sahina Bose a écrit :</p>
<blockquote type="cite" style="padding-left:5px; border-left:#1010ff 2px solid; margin-left:5px; width:100%"><!-- html ignored --><!-- head ignored --><!-- meta ignored -->Could you provide vdsm log from host "ovirt02" - the snippet containing output of 'GlusterVolume.list'<br /><br /> Also, the output of<br /><br /> su - postgres -c "psql -d engine -c \" select * from gluster_server where server_id = '0d1284e1-fa18-4309-b196-df9a6a337c44'; \"" <br /> assuming your database is "engine"<br /><br /><br />
<div class="moz-cite-prefix">On 11/09/2015 07:48 PM, Bello Florent wrote:</div>
<blockquote type="cite" style="padding-left:5px; border-left:#1010ff 2px solid; margin-left:5px; width:100%">
<p>Hi,</p>
<p>I activate gluster service in Cluster, then my engine.log chain : Could not add brick xxx to volume xxxx server uuid xxx not found in cluster.<br /> I found in mailing list i have to put all my hosts in maintenance mode and put on.</p>
<p>Then now engine.log chain :</p>
<p>2015-11-09 11:15:53,563 INFO [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-64) [] START, GlusterVolumesListVDSCommand(HostName = ovirt02, GlusterVolumesListVDSParameters:{runAsync='true', hostId='0d1284e1-fa18-4309-b196-df9a6a337c44'}), log id: 6ddd5b9d<br /> 2015-11-09 11:15:53,711 WARN [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could not associate brick 'ovirt01.mafia.kru:/gfs1/engine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<br /> 2015-11-09 11:15:53,714 WARN [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could not associate brick 'ovirt02.mafia.kru:/gfs1/engine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<br /> 2015-11-09 11:15:53,716 WARN [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could not associate brick 'ovirt03.mafia.kru:/gfs1/engine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<br /> 2015-11-09 11:15:53,719 WARN [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could not associate brick 'ovirt01.mafia.kru:/gfs2/engine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<br /> 2015-11-09 11:15:53,722 WARN [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could not associate brick 'ovirt02.mafia.kru:/gfs2/engine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<br /> 2015-11-09 11:15:53,725 WARN [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could not associate brick 'ovirt03.mafia.kru:/gfs2/engine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<br /> 2015-11-09 11:15:53,732 INFO [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-64) [] FINISH, GlusterVolumesListVDSCommand, return: {e9a24161-3e72-47ea-b593-57f3302e7c4e=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7eafe244, e5df896f-b818-4d70-ac86-ad9270f9d5f2=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@cb7d0349}, log id: 6ddd5b9d</p>
<p> </p>
<p>Here my vdsm.log on host 1:</p>
<p>Thread-4247::DEBUG::2015-11-09 11:17:47,621::__init__::533::jsonrpc.JsonRpcServer::(_serveRequest) Return 'Host.getVMFullList' in bridge with [{u'status': 'Up', u'nicModel': u'rtl8139,pv', u'kvmEnable': u'true', u'smp': u'1', u'emulatedMachine': u'pc', u'afterMigrationStatus': u'', 'pid': '4450', u'vmId': u'3930e6e3-5b41-45c3-bb7c-2af8563cefab', u'devices': [{u'alias': u'console0', u'specParams': {}, 'deviceType': u'console', u'deviceId': u'ab824f92-f636-4c0f-96ad-b4f3d1c352be', u'device': u'console', u'type': u'console'}, {u'target': 1572864, u'alias': u'balloon0', u'specParams': {u'model': u'none'}, 'deviceType': u'balloon', u'device': u'memballoon', u'type': u'balloon'}, {u'device': u'unix', u'alias': u'channel0', 'deviceType': u'channel', u'type': u'channel', u'address': {u'bus': u'0', u'controller': u'0', u'type': u'virtio-serial', u'port': u'1'}}, {u'device': u'unix', u'alias': u'channel1', 'deviceType': u'channel', u'type': u'channel', u'address': {u'bus': u'0', u'controller': u'0', u'type': u'virtio-serial', u'port': u'2'}}, {u'device': u'unix', u'alias': u'channel2', 'deviceType': u'channel', u'type': u'channel', u'address': {u'bus': u'0', u'controller': u'0', u'type': u'virtio-serial', u'port': u'3'}}, {u'alias': u'scsi0', 'deviceType': u'controller', u'address': {u'slot': u'0x04', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}, u'device': u'scsi', u'model': u'virtio-scsi', u'type': u'controller'}, {u'device': u'usb', u'alias': u'usb0', 'deviceType': u'controller', u'type': u'controller', u'address': {u'slot': u'0x01', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x2'}}, {u'device': u'ide', u'alias': u'ide0', 'deviceType': u'controller', u'type': u'controller', u'address': {u'slot': u'0x01', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x1'}}, {u'device': u'virtio-serial', u'alias': u'virtio-serial0', 'deviceType': u'controller', u'type': u'controller', u'address': {u'slot': u'0x05', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}}, {u'device': u'', u'alias': u'video0', 'deviceType': u'video', u'type': u'video', u'address': {u'slot': u'0x02', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}}, {u'device': u'vnc', u'specParams': {u'spiceSecureChannels': u'smain,sdisplay,sinputs,scursor,splayback,srecord,ssmartcard,susbredir', u'displayIp': '0'}, 'deviceType': u'graphics', u'type': u'graphics', u'port': u'5900'}, {u'nicModel': u'pv', u'macAddr': u'00:16:3e:43:96:7b', u'linkActive': True, u'network': u'ovirtmgmt', u'specParams': {}, u'filter': u'vdsm-no-mac-spoofing', u'alias': u'net0', 'deviceType': u'interface', u'deviceId': u'c2913ff3-fea3-4b17-a4b3-83398d920cd3', u'address': {u'slot': u'0x03', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}, u'device': u'bridge', u'type': u'interface', u'name': u'vnet0'}, {u'index': u'2', u'iface': u'ide', u'name': u'hdc', u'alias': u'ide0-1-0', u'specParams': {}, u'readonly': 'True', 'deviceType': u'disk', u'deviceId': u'13f4e285-c161-46f5-9ec3-ba1f92f374d9', u'address': {u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}, u'device': u'cdrom', u'shared': u'false', u'path': '', u'type': u'disk'}, {u'poolID': u'00000000-0000-0000-0000-000000000000', u'volumeInfo': {'domainID': u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': u'56461302-0710-4df0-964d-5e7b1ff07828', 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3'}, u'index': u'0', u'iface': u'virtio', u'apparentsize': '26843545600', u'specParams': {}, u'imageID': u'56461302-0710-4df0-964d-5e7b1ff07828', u'readonly': 'False', 'deviceType': u'disk', u'shared': u'exclusive', u'truesize': '3515854848', u'type': u'disk', u'domainID': u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', u'reqsize': u'0', u'format': u'raw', u'deviceId': u'56461302-0710-4df0-964d-5e7b1ff07828', u'address': {u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}, u'device': u'disk', u'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', u'propagateErrors': u'off', u'optional': u'false', u'name': u'vda', u'bootOrder': u'1', u'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', u'alias': u'virtio-disk0', u'volumeChain': [{'domainID': u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': u'56461302-0710-4df0-964d-5e7b1ff07828', 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3'}]}], u'guestDiskMapping': {}, u'spiceSecureChannels': u'smain,sdisplay,sinputs,scursor,splayback,srecord,ssmartcard,susbredir', u'vmType': u'kvm', u'displayIp': '0', u'displaySecurePort': '-1', u'memSize': 1536, u'displayPort': u'5900', u'cpuType': u'Conroe', 'clientIp': u'', u'statusTime': '4299704920', u'vmName': u'HostedEngine', u'display': 'vnc'}]<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:48,004::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57851<br /> Reactor thread::DEBUG::2015-11-09 11:17:48,012::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:48,013::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57851<br /> Reactor thread::DEBUG::2015-11-09 11:17:48,013::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57851)<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:48,013::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57851<br /> Thread-4248::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:48,015::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57851 started<br /> Thread-4248::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:48,022::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57851 stopped<br /> Thread-303::DEBUG::2015-11-09 11:17:48,143::fileSD::173::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_data/0af99439-f140-4636-90f7-f43904735da0/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)<br /> Thread-303::DEBUG::2015-11-09 11:17:48,154::fileSD::173::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n461 bytes (461 B) copied, 0.000382969 s, 1.2 MB/s\n'; <rc> = 0<br /> mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:48,767::storage_<a class="moz-txt-link-freetext" href="mailbox::735::Storage.Misc.excCmd::(_checkForMail)">mailbox::735::Storage.Misc.excCmd::(_checkForMail)</a> dd if=/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None)<br /> mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:48,783::storage_<a class="moz-txt-link-freetext" href="mailbox::735::Storage.Misc.excCmd::(_checkForMail)">mailbox::735::Storage.Misc.excCmd::(_checkForMail)</a> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.00507258 s, 202 MB/s\n'; <rc> = 0<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:49,939::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57852<br /> Reactor thread::DEBUG::2015-11-09 11:17:49,947::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:49,947::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57852<br /> Reactor thread::DEBUG::2015-11-09 11:17:49,947::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57852)<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:49,948::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57852<br /> Thread-4249::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:49,949::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57852 started<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,950::bindingxmlrpc::1257::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {}<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,962::netinfo::454::root::(_dhcp_used) DHCPv6 configuration not specified for ovirtmgmt.<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,963::netinfo::686::root::(_get_gateway) The gateway 10.10.10.254 is duplicated for the device ovirtmgmt<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,965::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on enp2s0.<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,965::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on enp2s0.<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,968::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on bond0.<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,968::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on bond0.<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,970::netinfo::686::root::(_get_gateway) The gateway 10.10.10.254 is duplicated for the device ovirtmgmt<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,971::utils::676::root::(execCmd) /usr/sbin/tc qdisc show (cwd None)<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,979::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,980::utils::676::root::(execCmd) /usr/sbin/tc class show dev enp2s0 classid 0:1388 (cwd None)<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,989::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,993::caps::807::root::(_getKeyPackages) rpm package ('glusterfs-rdma',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,997::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-object',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:49,997::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-proxy',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:50,001::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-plugin',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:50,002::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:50,002::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-container',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:50,003::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-account',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:50,003::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-doc',) not found<br /> Thread-4249::DEBUG::2015-11-09 11:17:50,005::bindingxmlrpc::1264::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1954deeb7a38'}], 'FC': []}, 'packages2': {'kernel': {'release': '229.20.1.el7.x86_64', 'buildtime': 1446588607.0, 'version': '3.10.0'}, 'glusterfs-fuse': {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7.5'}, 'spice-server': {'release': '9.el7_1.3', 'buildtime': 1444691699L, 'version': '0.12.4'}, 'librbd1': {'release': '2.el7', 'buildtime': 1425594433L, 'version': '0.80.7'}, 'vdsm': {'release': '0.el7.centos', 'buildtime': 1446474396L, 'version': '4.17.10.1'}, 'qemu-kvm': {'release': '29.1.el7', 'buildtime': 1444310806L, 'version': '2.3.0'}, 'glusterfs': {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7.5'}, 'libvirt': {'release': '16.el7_1.5', 'buildtime': 1446559281L, 'version': '1.2.8'}, 'qemu-img': {'release': '29.1.el7', 'buildtime': 1444310806L, 'version': '2.3.0'}, 'mom': {'release': '2.el7', 'buildtime': 1442501481L, 'version': '0.5.1'}, 'glusterfs-geo-replication': {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7.5'}, 'glusterfs-server': {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7.5'}, 'glusterfs-cli': {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7.5'}}, 'numaNodeDistance': {'0': [10]}, 'cpuModel': 'Intel(R) Core(TM)2 Quad CPU Q8400 @ 2.66GHz', 'liveMerge': 'true', 'hooks': {'before_vm_start': {'50_hostedengine': {'md5': '2a6d96c26a3599812be6cf1a13d9f485'}}}, 'vmTypes': ['kvm'], 'selinux': {'mode': '-1'}, 'liveSnapshot': 'true', 'kdumpStatus': 0, 'networks': {'ovirtmgmt': {'iface': 'ovirtmgmt', 'addr': '10.10.10.211', 'cfg': {'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'IPADDR': '10.10.10.211', 'HOTPLUG': 'no', 'GATEWAY': '10.10.10.254', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'STP': 'off', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'bridged': True, 'ipv6addrs': ['fe80::6e62:6dff:feb3:3b72/64'], 'gateway': '10.10.10.254', 'dhcpv4': False, 'netmask': '255.255.255.0', 'dhcpv6': False, 'stp': 'off', 'ipv4addrs': ['10.10.10.211/24'], 'mtu': '1500', 'ipv6gateway': '::', 'ports': ['vnet0', 'enp2s0']}}, 'bridges': {'ovirtmgmt': {'addr': '10.10.10.211', 'cfg': {'IPV6INIT': 'no', 'DEFROUTE': 'yes', 'IPADDR': '10.10.10.211', 'HOTPLUG': 'no', 'GATEWAY': '10.10.10.254', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'STP': 'off', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'ipv6addrs': ['fe80::6e62:6dff:feb3:3b72/64'], 'gateway': '10.10.10.254', 'dhcpv4': False, 'netmask': '255.255.255.0', 'dhcpv6': False, 'stp': 'off', 'ipv4addrs': ['10.10.10.211/24'], 'mtu': '1500', 'ipv6gateway': '::', 'ports': ['vnet0', 'enp2s0'], 'opts': {'multicast_last_member_count': '2', 'hash_elasticity': '4', 'multicast_query_response_interval': '1000', 'group_fwd_mask': '0x0', 'multicast_snooping': '1', 'multicast_startup_query_interval': '3125', 'hello_timer': '172', 'multicast_querier_interval': '25500', 'max_age': '2000', 'hash_max': '512', 'stp_state': '0', 'topology_change_detected': '0', 'priority': '32768', 'multicast_membership_interval': '26000', 'root_path_cost': '0', 'root_port': '0', 'multicast_querier': '0', 'multicast_startup_query_count': '2', 'nf_call_iptables': '0', 'topology_change': '0', 'hello_time': '200', 'root_id': '8000.6c626db33b72', 'bridge_id': '8000.6c626db33b72', 'topology_change_timer': '0', 'ageing_time': '30000', 'nf_call_ip6tables': '0', 'gc_timer': '25099', 'nf_call_arptables': '0', 'group_addr': '1:80:c2:0:0:0', 'multicast_last_member_interval': '100', 'default_pvid': '1', 'multicast_query_interval': '12500', 'tcn_timer': '0', 'multicast_router': '1', 'vlan_filtering': '0', 'forward_delay': '0'}}}, 'uuid': 'c2cac9d6-9ed7-44f0-8bbc-eff4c71db7ca', 'onlineCpus': '0,1,2,3', 'nics': {'enp2s0': {'addr': '', 'ipv6gateway': '::', 'ipv6addrs': ['fe80::6e62:6dff:feb3:3b72/64'], 'mtu': '1500', 'dhcpv4': False, 'netmask': '', 'dhcpv6': False, 'ipv4addrs': [], 'cfg': {'BRIDGE': 'ovirtmgmt', 'IPV6INIT': 'no', 'NM_CONTROLLED': 'no', 'HWADDR': '6c:62:6d:b3:3b:72', 'BOOTPROTO': 'none', 'DEVICE': 'enp2s0', 'ONBOOT': 'yes'}, 'hwaddr': '6c:62:6d:b3:3b:72', 'speed': 1000, 'gateway': ''}}, 'software_revision': '0', 'hostdevPassthrough': 'false', 'clusterLevels': ['3.4', '3.5', '3.6'], 'cpuFlags': 'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,nopl,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,sse4_1,xsave,lahf_lm,dtherm,tpr_shadow,vnmi,flexpriority,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1954deeb7a38', 'netConfigDirty': 'False', 'supportedENGINEs': ['3.4', '3.5', '3.6'], 'autoNumaBalancing': 0, 'additionalFeatures': ['GLUSTER_SNAPSHOT', 'GLUSTER_GEO_REPLICATION', 'GLUSTER_BRICK_MANAGEMENT'], 'reservedMem': '321', 'bondings': {'bond0': {'ipv4addrs': [], 'addr': '', 'cfg': {'BOOTPROTO': 'none'}, 'ipv6addrs': [], 'active_slave': '', 'mtu': '1500', 'dhcpv4': False, 'netmask': '', 'dhcpv6': False, 'slaves': [], 'hwaddr': 'ba:5f:22:a3:17:07', 'ipv6gateway': '::', 'gateway': '', 'opts': {}}}, 'software_version': '4.17', 'memSize': '3782', 'cpuSpeed': '2670.000', 'numaNodes': {'0': {'totalMemory': '3782', 'cpus': [0, 1, 2, 3]}}, 'cpuSockets': '1', 'vlans': {}, 'lastClientIface': 'lo', 'cpuCores': '4', 'kvmEnabled': 'true', 'guestOverhead': '65', 'version_name': 'Snow Man', 'cpuThreads': '4', 'emulatedMachines': ['pc-i440fx-rhel7.1.0', 'rhel6.3.0', 'pc-q35-rhel7.2.0', 'pc-i440fx-rhel7.0.0', 'rhel6.1.0', 'rhel6.6.0', 'rhel6.2.0', 'pc', 'pc-q35-rhel7.0.0', 'pc-q35-rhel7.1.0', 'q35', 'pc-i440fx-rhel7.2.0', 'rhel6.4.0', 'rhel6.0.0', 'rhel6.5.0'], 'rngSources': ['random'], 'operatingSystem': {'release': '1.1503.el7.centos.2.8', 'version': '7', 'name': 'RHEL'}, 'lastClient': '127.0.0.1'}}<br /> Thread-4249::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:50,020::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57852 stopped<br /> mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:50,797::storage_<a class="moz-txt-link-freetext" href="mailbox::735::Storage.Misc.excCmd::(_checkForMail)">mailbox::735::Storage.Misc.excCmd::(_checkForMail)</a> dd if=/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None)<br /> mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:50,815::storage_<a class="moz-txt-link-freetext" href="mailbox::735::Storage.Misc.excCmd::(_checkForMail)">mailbox::735::Storage.Misc.excCmd::(_checkForMail)</a> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.00511026 s, 200 MB/s\n'; <rc> = 0<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,098::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57853<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,106::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,107::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57853<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,107::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57853)<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,108::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57853<br /> Thread-4250::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,110::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57853 started<br /> Thread-4250::DEBUG::2015-11-09 11:17:52,111::bindingxmlrpc::1257::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {}<br /> Thread-4250::DEBUG::2015-11-09 11:17:52,112::bindingxmlrpc::1264::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'MS-7529', 'systemSerialNumber': 'To Be Filled By O.E.M.', 'systemFamily': 'To Be Filled By O.E.M.', 'systemVersion': '1.0', 'systemUUID': '00000000-0000-0000-0000-6C626DB33B72', 'systemManufacturer': 'MICRO-STAR INTERNATIONAL CO.,LTD'}}<br /> Thread-4250::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,114::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57853 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,116::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57854<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,124::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,124::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57854<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,125::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57854<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,125::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57854)<br /> Thread-4251::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,128::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57854 started<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,129::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,130::task::595::Storage.TaskManager.Task::(_updateState) Task=`8535d95e-dce6-4474-bd8d-7824f68cf68a`::moving from state init -> state preparing<br /> Thread-4251::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,130::logUtils::48::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=7, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'id': '2c69bdcf-793b-4fda-b326-b8aa6c33ade0', 'vfs_type': 'glusterfs', 'connection': 'ovirt02.mafia.kru:/engine', 'user': 'kvm'}], options=None)<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,132::hsm::2417::Storage.HSM::(__prefetchDomains) glusterDomPath: glusterSD/*<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,146::hsm::2429::Storage.HSM::(__prefetchDomains) Found SD uuids: (u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', u'0af99439-f140-4636-90f7-f43904735da0')<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,147::hsm::2489::Storage.HSM::(connectStorageServer) knownSDs: {b4c488af-9d2f-4b7b-a6f6-74a0bac06c41: storage.glusterSD.findDomain, 0af99439-f140-4636-90f7-f43904735da0: storage.glusterSD.findDomain}<br /> Thread-4251::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,147::logUtils::51::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '2c69bdcf-793b-4fda-b326-b8aa6c33ade0'}]}<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,147::task::1191::Storage.TaskManager.Task::(prepare) Task=`8535d95e-dce6-4474-bd8d-7824f68cf68a`::finished: {'statuslist': [{'status': 0, 'id': '2c69bdcf-793b-4fda-b326-b8aa6c33ade0'}]}<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,147::task::595::Storage.TaskManager.Task::(_updateState) Task=`8535d95e-dce6-4474-bd8d-7824f68cf68a`::moving from state preparing -> state finished<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,147::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,148::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4251::DEBUG::2015-11-09 11:17:52,148::task::993::Storage.TaskManager.Task::(_decref) Task=`8535d95e-dce6-4474-bd8d-7824f68cf68a`::ref 0 aborting False<br /> Thread-4251::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,149::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57854 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,150::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57855<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,158::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,158::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57855<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,159::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57855<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,159::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57855)<br /> Thread-4255::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,162::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57855 started<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,162::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,163::task::595::Storage.TaskManager.Task::(_updateState) Task=`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::moving from state init -> state preparing<br /> Thread-4255::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,163::logUtils::48::dispatcher::(wrapper) Run and protect: getStorageDomainStats(sdUUID='b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', options=None)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,164::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`41531754-8ba9-4fc4-8788-d4d67fa33e5c`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2848' at 'getStorageDomainStats'<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,164::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared'<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,164::resourceManager::601::Storage.ResourceManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 'shared' (1 active user)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,164::resourceManager::238::Storage.ResourceManager.Request::(grant) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`41531754-8ba9-4fc4-8788-d4d67fa33e5c`::Granted request<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,165::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::_resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,165::task::993::Storage.TaskManager.Task::(_decref) Task=`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::ref 1 aborting False<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,166::iscsi::431::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,166::iscsiadm::97::Storage.Misc.excCmd::(_runCmd) /usr/bin/sudo -n /sbin/iscsiadm -m session -R (cwd None)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,183::misc::760::Storage.SamplingMethod::(__call__) Returning last result<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,183::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.hba.rescan)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,184::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,184::hba::56::Storage.HBA::(rescan) Starting scan<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,295::hba::62::Storage.HBA::(rescan) Scan finished<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,296::misc::760::Storage.SamplingMethod::(__call__) Returning last result<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,296::multipath::77::Storage.Misc.excCmd::(rescan) /usr/bin/sudo -n /usr/sbin/multipath (cwd None)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,362::multipath::77::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,362::utils::676::root::(execCmd) /sbin/udevadm settle --timeout=5 (cwd None)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,371::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,372::lvm::498::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,372::lvm::500::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::509::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::511::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::529::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::531::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,374::misc::760::Storage.SamplingMethod::(__call__) Returning last result<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,386::fileSD::157::Storage.StorageDomainManifest::(__init__) Reading domain in path /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,387::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,395::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=hosted_storage', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=ovirt02.mafia.kru:/engine', 'ROLE=Regular', 'SDUUID=b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'TYPE=GLUSTERFS', 'VERSION=3', '_SHA_CKSUM=cb09606ada74ed4155ad158923dd930264780fc8']<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,398::fileSD::647::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images []<br /> Thread-4255::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,399::sd::442::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace b4c488af-9d2f-4b7b-a6f6-74a0bac06c41_imageNS already registered<br /> Thread-4255::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,399::sd::450::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace b4c488af-9d2f-4b7b-a6f6-74a0bac06c41_volumeNS already registered<br /> Thread-4255::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,400::logUtils::51::dispatcher::(wrapper) Run and protect: getStorageDomainStats, Return response: {'stats': {'mdasize': 0, 'mdathreshold': True, 'mdavalid': True, 'diskfree': '210878988288', 'disktotal': '214643507200', 'mdafree': 0}}<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,401::task::1191::Storage.TaskManager.Task::(prepare) Task=`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::finished: {'stats': {'mdasize': 0, 'mdathreshold': True, 'mdavalid': True, 'diskfree': '210878988288', 'disktotal': '214643507200', 'mdafree': 0}}<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,401::task::595::Storage.TaskManager.Task::(_updateState) Task=`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::moving from state preparing -> state finished<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,401::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>}<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,401::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,402::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41'<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,402::resourceManager::635::Storage.ResourceManager::(releaseResource) Released resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users)<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,402::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free, finding out if anyone is waiting for it.<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,402::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', Clearing records.<br /> Thread-4255::DEBUG::2015-11-09 11:17:52,402::task::993::Storage.TaskManager.Task::(_decref) Task=`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::ref 0 aborting False<br /> Thread-4255::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,404::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57855 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,405::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57856<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,413::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,414::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57856<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,414::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57856<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,414::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57856)<br /> Thread-4259::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,417::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57856 started<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,418::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,418::task::595::Storage.TaskManager.Task::(_updateState) Task=`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::moving from state init -> state preparing<br /> Thread-4259::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,419::logUtils::48::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID='00000000-0000-0000-0000-000000000000', imgUUID='56461302-0710-4df0-964d-5e7b1ff07828', leafUUID='8f8ee034-de86-4438-b6eb-9109faa8b3d3')<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,419::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`bec7c8c3-42b9-4acb-88cf-841d9dc28fb0`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3205' at 'prepareImage'<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,419::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared'<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,420::resourceManager::601::Storage.ResourceManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 'shared' (1 active user)<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,420::resourceManager::238::Storage.ResourceManager.Request::(grant) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`bec7c8c3-42b9-4acb-88cf-841d9dc28fb0`::Granted request<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,420::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::_resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared)<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,420::task::993::Storage.TaskManager.Task::(_decref) Task=`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::ref 1 aborting False<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,445::fileSD::536::Storage.StorageDomain::(activateVolumes) Fixing permissions on /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,446::fileUtils::143::Storage.fileUtils::(createdir) Creating directory: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 mode: None<br /> Thread-4259::WARNING::2015-11-09 11:17:52,446::fileUtils::152::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 already exists<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,446::fileSD::511::Storage.StorageDomain::(createImageLinks) Creating symlink from /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828 to /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/56461302-0710-4df0-964d-5e7b1ff07828<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,447::fileSD::516::Storage.StorageDomain::(createImageLinks) img run dir already exists: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/56461302-0710-4df0-964d-5e7b1ff07828<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,448::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 8f8ee034-de86-4438-b6eb-9109faa8b3d3<br /> Thread-4259::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,450::logUtils::51::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-5e7b1ff07828'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-5e7b1ff07828'}]}<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,450::task::1191::Storage.TaskManager.Task::(prepare) Task=`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::finished: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-5e7b1ff07828'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-5e7b1ff07828'}]}<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,450::task::595::Storage.TaskManager.Task::(_updateState) Task=`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::moving from state preparing -> state finished<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,450::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>}<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,450::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,451::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41'<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,451::resourceManager::635::Storage.ResourceManager::(releaseResource) Released resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users)<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,451::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free, finding out if anyone is waiting for it.<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,451::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', Clearing records.<br /> Thread-4259::DEBUG::2015-11-09 11:17:52,451::task::993::Storage.TaskManager.Task::(_decref) Task=`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::ref 0 aborting False<br /> Thread-4259::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,454::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57856 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,454::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57857<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,463::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,463::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57857<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,464::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57857)<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,464::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57857<br /> Thread-4260::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,466::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57857 started<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,467::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,467::task::595::Storage.TaskManager.Task::(_updateState) Task=`aed16a50-ede9-4ff5-92ef-356692fd56ae`::moving from state init -> state preparing<br /> Thread-4260::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,467::logUtils::48::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID='00000000-0000-0000-0000-000000000000', imgUUID='fd81353f-b654-4493-bcaf-2f417849b830', leafUUID='8bb29fcb-c109-4f0a-a227-3819b6ecfdd9')<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`974119cd-1351-46e9-8062-ffb1298c4ac9`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3205' at 'prepareImage'<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared'<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::601::Storage.ResourceManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 'shared' (1 active user)<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::238::Storage.ResourceManager.Request::(grant) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`974119cd-1351-46e9-8062-ffb1298c4ac9`::Granted request<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,469::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=`aed16a50-ede9-4ff5-92ef-356692fd56ae`::_resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared)<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,469::task::993::Storage.TaskManager.Task::(_decref) Task=`aed16a50-ede9-4ff5-92ef-356692fd56ae`::ref 1 aborting False<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,485::fileSD::536::Storage.StorageDomain::(activateVolumes) Fixing permissions on /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,486::fileUtils::143::Storage.fileUtils::(createdir) Creating directory: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 mode: None<br /> Thread-4260::WARNING::2015-11-09 11:17:52,487::fileUtils::152::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 already exists<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,487::fileSD::511::Storage.StorageDomain::(createImageLinks) Creating symlink from /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830 to /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-4493-bcaf-2f417849b830<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,487::fileSD::516::Storage.StorageDomain::(createImageLinks) img run dir already exists: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-4493-bcaf-2f417849b830<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,488::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 8bb29fcb-c109-4f0a-a227-3819b6ecfdd9<br /> Thread-4260::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,490::logUtils::51::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}]}<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,490::task::1191::Storage.TaskManager.Task::(prepare) Task=`aed16a50-ede9-4ff5-92ef-356692fd56ae`::finished: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}]}<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,490::task::595::Storage.TaskManager.Task::(_updateState) Task=`aed16a50-ede9-4ff5-92ef-356692fd56ae`::moving from state preparing -> state finished<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,490::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>}<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41'<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::635::Storage.ResourceManager::(releaseResource) Released resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users)<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free, finding out if anyone is waiting for it.<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', Clearing records.<br /> Thread-4260::DEBUG::2015-11-09 11:17:52,492::task::993::Storage.TaskManager.Task::(_decref) Task=`aed16a50-ede9-4ff5-92ef-356692fd56ae`::ref 0 aborting False<br /> Thread-4260::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,494::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57857 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,494::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57858<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,503::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,504::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57858<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,504::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57858<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,504::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57858)<br /> Thread-4261::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,507::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57858 started<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,508::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,508::task::595::Storage.TaskManager.Task::(_updateState) Task=`d39463fd-486f-4280-903a-51b72862b648`::moving from state init -> state preparing<br /> Thread-4261::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,509::logUtils::48::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID='00000000-0000-0000-0000-000000000000', imgUUID='0e1c20d1-94aa-4003-8e12-0dbbf06a6af8', leafUUID='3fc3362d-ab6d-4e06-bd72-82d5750c7095')<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,509::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`240c2aba-6c2e-44da-890d-c3d605e1933f`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3205' at 'prepareImage'<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,509::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared'<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,509::resourceManager::601::Storage.ResourceManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 'shared' (1 active user)<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,510::resourceManager::238::Storage.ResourceManager.Request::(grant) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`240c2aba-6c2e-44da-890d-c3d605e1933f`::Granted request<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,510::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=`d39463fd-486f-4280-903a-51b72862b648`::_resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared)<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,510::task::993::Storage.TaskManager.Task::(_decref) Task=`d39463fd-486f-4280-903a-51b72862b648`::ref 1 aborting False<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,526::fileSD::536::Storage.StorageDomain::(activateVolumes) Fixing permissions on /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,528::fileUtils::143::Storage.fileUtils::(createdir) Creating directory: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 mode: None<br /> Thread-4261::WARNING::2015-11-09 11:17:52,528::fileUtils::152::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 already exists<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,528::fileSD::511::Storage.StorageDomain::(createImageLinks) Creating symlink from /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8 to /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,528::fileSD::516::Storage.StorageDomain::(createImageLinks) img run dir already exists: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,530::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 3fc3362d-ab6d-4e06-bd72-82d5750c7095<br /> Thread-4261::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,531::logUtils::51::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'volumeID': u'3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94aa-4003-8e12-0dbbf06a6af8'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'volumeID': u'3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94aa-4003-8e12-0dbbf06a6af8'}]}<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,531::task::1191::Storage.TaskManager.Task::(prepare) Task=`d39463fd-486f-4280-903a-51b72862b648`::finished: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'volumeID': u'3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94aa-4003-8e12-0dbbf06a6af8'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'volumeID': u'3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94aa-4003-8e12-0dbbf06a6af8'}]}<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,532::task::595::Storage.TaskManager.Task::(_updateState) Task=`d39463fd-486f-4280-903a-51b72862b648`::moving from state preparing -> state finished<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>}<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41'<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::635::Storage.ResourceManager::(releaseResource) Released resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users)<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,533::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free, finding out if anyone is waiting for it.<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,533::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', Clearing records.<br /> Thread-4261::DEBUG::2015-11-09 11:17:52,533::task::993::Storage.TaskManager.Task::(_decref) Task=`d39463fd-486f-4280-903a-51b72862b648`::ref 0 aborting False<br /> Thread-4261::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,535::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57858 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,536::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57859<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,544::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,545::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57859<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,545::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57859)<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,545::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57859<br /> Thread-4262::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,548::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57859 started<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,548::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,549::task::595::Storage.TaskManager.Task::(_updateState) Task=`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::moving from state init -> state preparing<br /> Thread-4262::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,549::logUtils::48::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID='00000000-0000-0000-0000-000000000000', imgUUID='350fb787-049a-4174-8914-f371aabfa72c', leafUUID='02c5d59d-638c-4672-814d-d734e334e24a')<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,549::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`fd9ea6d0-3a31-4ec6-a74c-8b84b2e51746`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3205' at 'prepareImage'<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,550::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared'<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,550::resourceManager::601::Storage.ResourceManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 'shared' (1 active user)<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,550::resourceManager::238::Storage.ResourceManager.Request::(grant) ResName=`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=`fd9ea6d0-3a31-4ec6-a74c-8b84b2e51746`::Granted request<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,550::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::_resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared)<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,551::task::993::Storage.TaskManager.Task::(_decref) Task=`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::ref 1 aborting False<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,566::fileSD::536::Storage.StorageDomain::(activateVolumes) Fixing permissions on /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,568::fileUtils::143::Storage.fileUtils::(createdir) Creating directory: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 mode: None<br /> Thread-4262::WARNING::2015-11-09 11:17:52,568::fileUtils::152::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 already exists<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,568::fileSD::511::Storage.StorageDomain::(createImageLinks) Creating symlink from /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c to /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb787-049a-4174-8914-f371aabfa72c<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,568::fileSD::516::Storage.StorageDomain::(createImageLinks) img run dir already exists: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb787-049a-4174-8914-f371aabfa72c<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,570::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 02c5d59d-638c-4672-814d-d734e334e24a<br /> Thread-4262::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,572::logUtils::51::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeID': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeID': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}]}<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,573::task::1191::Storage.TaskManager.Task::(prepare) Task=`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::finished: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeID': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeID': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}]}<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,573::task::595::Storage.TaskManager.Task::(_updateState) Task=`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::moving from state preparing -> state finished<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,573::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>}<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,573::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,573::resourceManager::616::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41'<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,573::resourceManager::635::Storage.ResourceManager::(releaseResource) Released resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users)<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,574::resourceManager::641::Storage.ResourceManager::(releaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free, finding out if anyone is waiting for it.<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,574::resourceManager::649::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', Clearing records.<br /> Thread-4262::DEBUG::2015-11-09 11:17:52,574::task::993::Storage.TaskManager.Task::(_decref) Task=`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::ref 0 aborting False<br /> Thread-4262::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,576::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57859 stopped<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,610::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57860<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,619::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11<br /> Reactor thread::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,619::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57860<br /> BindingXMLRPC::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,620::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57860<br /> Reactor thread::DEBUG::2015-11-09 11:17:52,620::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('127.0.0.1', 57860)<br /> Thread-4263::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,623::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57860 started<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,623::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1]<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,624::task::595::Storage.TaskManager.Task::(_updateState) Task=`6fd1d011-d931-4eca-b93b-c0fc3a1b4107`::moving from state init -> state preparing<br /> Thread-4263::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,624::logUtils::48::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br /> Thread-4263::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,624::logUtils::51::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000392118', 'lastCheck': '6.0', 'valid': True}, u'0af99439-f140-4636-90f7-f43904735da0': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000382969', 'lastCheck': '4.5', 'valid': True}}<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,624::task::1191::Storage.TaskManager.Task::(prepare) Task=`6fd1d011-d931-4eca-b93b-c0fc3a1b4107`::finished: {'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000392118', 'lastCheck': '6.0', 'valid': True}, u'0af99439-f140-4636-90f7-f43904735da0': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000382969', 'lastCheck': '4.5', 'valid': True}}<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,625::task::595::Storage.TaskManager.Task::(_updateState) Task=`6fd1d011-d931-4eca-b93b-c0fc3a1b4107`::moving from state preparing -> state finished<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,625::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,625::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br /> Thread-4263::DEBUG::2015-11-09 11:17:52,625::task::993::Storage.TaskManager.Task::(_decref) Task=`6fd1d011-d931-4eca-b93b-c0fc3a1b4107`::ref 0 aborting False<br /> Thread-4263::<a class="moz-txt-link-freetext" href="INFO::2015-11-09">INFO::2015-11-09</a> 11:17:52,627::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57860 stopped<br /> mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:52,829::storage_<a class="moz-txt-link-freetext" href="mailbox::735::Storage.Misc.excCmd::(_checkForMail)">mailbox::735::Storage.Misc.excCmd::(_checkForMail)</a> dd if=/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None)<br /> mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:52,845::storage_<a class="moz-txt-link-freetext" href="mailbox::735::Storage.Misc.excCmd::(_checkForMail)">mailbox::735::Storage.Misc.excCmd::(_checkForMail)</a> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.00494757 s, 207 MB/s\n'; <rc> = 0<br /><br /></p>
<div>-- <br />
<p>Florent BELLO<br /> Service Informatique<br /><a class="moz-txt-link-abbreviated" href="mailto:informatique@ville-kourou.fr">informatique@ville-kourou.fr</a><br /> 0594 22 31 22<br /> Mairie de Kourou</p>
</div>
<br /><fieldset class="mimeAttachmentHeader"></fieldset><br />
<pre>_______________________________________________
Users mailing list
<a class="moz-txt-link-abbreviated" href="mailto:Users@ovirt.org">Users@ovirt.org</a>
<a class="moz-txt-link-freetext" href="http://lists.ovirt.org/mailman/listinfo/users">http://lists.ovirt.org/mailman/listinfo/users</a>
</pre>
</blockquote>
</blockquote>
</body></html>