Users

Download

users@ovirt.org

November 2015

167 participants
244 discussions

[SOLVED] Re: Trying to make ovirt-hosted-engine-setup create a customized Engine-vm on 3.6 HC HE
by Giuseppe Ragusa 25 Nov '15

25 Nov '15

On Mon, Oct 26, 2015, at 09:48, Simone Tiraboschi wrote: > > > On Mon, Oct 26, 2015 at 12:14 AM, Giuseppe Ragusa <giuseppe.ragusa(a)hotmail.com> wrote: >> Hi all, >> I'm experiencing some difficulties using oVirt 3.6 latest snapshot. >> >> I'm trying to trick the self-hosted-engine setup to create a custom engine vm with 3 nics (with fixed MACs/UUIDs). >> >> The GlusterFS volume (3.7.5 hyperconverged, replica 3, for the engine vm) and the network bridges (ovirtmgmt and other two bridges, called nfs and lan, for the engine vm) have been preconfigured on the initial fully-patched CentOS 7.1 host (plus other two identical hosts which are awaiting to be added). >> >> I'm stuck at a point with the engine vm successfully starting but with only one nic present (connected to the ovirtmgmt bridge). >> >> I'm trying to obtain the modified engine vm by means of a trick which used to work in a previous (aborted because of lacking GlusterFS-by-libgfapi support) oVirt 3.5 test setup (about a year ago, maybe more): I'm substituting the standard /usr/share/ovirt-hosted-engine-setup/templates/vm.conf.in with the following: >> >> vmId=@VM_UUID@ >> memSize=@MEM_SIZE@ >> display=@CONSOLE_TYPE@ >> devices={index:2,iface:ide,address:{ controller:0, target:0,unit:0, bus:1, type:drive},specParams:{},readonly:true,deviceId:@CDROM_UUID@,path:@CDROM@,device:cdrom,shared:false,type:disk@BOOT_CDROM@} >> devices={index:0,iface:virtio,format:raw,poolID:@SP_UUID@,volumeID:@VOL_UUID@,imageID:@IMG_UUID@,specParams:{},readonly:false,domainID:@SD_UUID@,optional:false,deviceId:@IMG_UUID@,address:{bus:0x00, slot:0x06, domain:0x0000, type:pci, function:0x0},device:disk,shared:exclusive,propagateErrors:off,type:disk@BOOT_DISK@} >> devices={device:scsi,model:virtio-scsi,type:controller} >> devices={index:4,nicModel:pv,macAddr:02:50:56:3f:c4:b0,linkActive:true,network:@BRIDGE@,filter:vdsm-no-mac-spoofing,specParams:{},deviceId:@NIC_UUID@,address:{bus:0x00, slot:0x03, domain:0x0000, type:pci, function:0x0},device:bridge,type:interface@BOOT_PXE@} >> devices={index:8,nicModel:pv,macAddr:02:50:56:3f:c4:a0,linkActive:true,network:lan,filter:vdsm-no-mac-spoofing,specParams:{},deviceId:6c467650-1837-47ea-89bc-1113f4bfefee,address:{bus:0x00, slot:0x09, domain:0x0000, type:pci, function:0x0},device:bridge,type:interface@BOOT_PXE@} >> devices={index:16,nicModel:pv,macAddr:02:50:56:3f:c4:c0,linkActive:true,network:nfs,filter:vdsm-no-mac-spoofing,specParams:{},deviceId:4d8e0705-8cb4-45b7-b960-7f98bb59858d,address:{bus:0x00, slot:0x0c, domain:0x0000, type:pci, function:0x0},device:bridge,type:interface@BOOT_PXE@} >> devices={device:console,specParams:{},type:console,deviceId:@CONSOLE_UUID@,alias:console0} >> vmName=@NAME@ >> spiceSecureChannels=smain,sdisplay,sinputs,scursor,splayback,srecord,ssmartcard,susbredir >> smp=@VCPUS@ >> cpuType=@CPU_TYPE@ >> emulatedMachine=@EMULATED_MACHINE@ >> >> but unfortunately the vm gets created like this (output from "ps"; note that I'm attaching a CentOS7.1 Netinstall ISO with an embedded kickstart: the installation should proceed by HTTP on the lan network but obviously fails): >> >> /usr/libexec/qemu-kvm -name HostedEngine -S -machine >> pc-i440fx-rhel7.1.0,accel=kvm,usb=off -cpu Westmere -m 4096 -realtime mlock=off >> -smp 2,sockets=2,cores=1,threads=1 -uuid f49da721-8aa6-4422-8b91-e91a0e38aa4a -s >> mbios type=1,manufacturer=oVirt,product=oVirt Node,version=7-1.1503.el7.centos.2 >> .8,serial=2a1855a9-18fb-4d7a-b8b8-6fc898a8e827,uuid=f49da721-8aa6-4422-8b91-e91a >> 0e38aa4a -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/li >> b/libvirt/qemu/HostedEngine.monitor,server,nowait -mon chardev=charmonitor,id=mo >> nitor,mode=control -rtc base=2015-10-25T11:22:22,driftfix=slew -global kvm-pit.l >> ost_tick_policy=discard -no-hpet -no-reboot -boot strict=on -device piix3-usb-uh >> ci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr >> =0x4 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x5 -drive file= >> /var/tmp/engine.iso,if=none,id=drive-ide0-1-0,readonly=on,format=raw,serial= -device ide-cd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=1 -drive file=/var/run/vdsm/storage/be4434bf-a5fd-44d7-8011-d5e4ac9cf523/b3abc1cb-8a78-4b56-a9b0-e5f41fea0fdc/8d075a8d-730a-4925-8779-e0ca2b3dbcf4,if=none,id=drive-virtio-disk0,format=raw,serial=b3abc1cb-8a78-4b56-a9b0-e5f41fea0fdc,cache=none,werror=stop,rerror=stop,aio=threads -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x6,drive=drive-virtio-disk0,id=virtio-disk0 -netdev tap,fd=26,id=hostnet0,vhost=on,vhostfd=27 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=02:50:56:3f:c4:b0,bus=pci.0,addr=0x3 -chardev socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/f49da721-8aa6-4422-8b91-e91a0e38aa4a.com.redhat.rhevm.vdsm,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.rhevm.vdsm -chardev socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/f49da721-8aa6-4422-8b91-e91a0e38aa4a.org.qemu.guest_agent.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,id=channel1,name=org.qemu.guest_agent.0 -chardev socket,id=charchannel2,path=/var/lib/libvirt/qemu/channels/f49da721-8aa6-4422-8b91-e91a0e38aa4a.org.ovirt.hosted-engine-setup.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=3,chardev=charchannel2,id=channel2,name=org.ovirt.hosted-engine-setup.0 -chardev socket,id=charconsole0,path=/var/run/ovirt-vmconsole-console/f49da721-8aa6-4422-8b91-e91a0e38aa4a.sock,server,nowait -device virtconsole,chardev=charconsole0,id=console0 -vnc 0:0,password -device cirrus-vga,id=video0,bus=pci.0,addr=0x2 -msg timestamp=on >> >> There seem to be no errors in the logs. >> >> I've tried reading some (limited) Python setup code but I've not found any obvious reason why the trick should not work anymore. >> >> I know that 3.6 has different network configuration/management and this could be the hot point. >> >> Does anyone have any further suggestion or clue (code/logs to read)? > > The VM creation path is now a bit different cause we use just vdscli library instead of vdsClient. > Please take a a look at mixins.py Many thanks for your very valuable hint: I've restored the original /usr/share/ovirt-hosted-engine-setup/templates/vm.conf.in and I've managed to obtain the 3-nics-customized vm by modifying /usr/lib/python2.7/site-packages/ovirt_hosted_engine_setup/mixins.py like this ("diff -Naur" output): ************************************************************************************ --- mixins.py.orig 2015-10-20 16:57:40.000000000 +0200 +++ mixins.py 2015-10-26 22:22:58.351223922 +0100 @@ -25,6 +25,7 @@ import random import string import time +import uuid from ovirt_hosted_engine_setup import constants as ohostedcons @@ -247,6 +248,44 @@ ]['@BOOT_PXE@'] == ',bootOrder:1': nic['bootOrder'] = '1' conf['devices'].append(nic) + nic2 = { + 'nicModel': 'pv', + 'macAddr': '02:50:56:3f:c4:a0', + 'linkActive': 'true', + 'network': 'lan', + 'filter': 'vdsm-no-mac-spoofing', + 'specParams': {}, + 'deviceId': str(uuid.uuid4()), + 'address': { + 'bus': '0x00', + 'slot': '0x09', + 'domain': '0x0000', + 'type': 'pci', + 'function': '0x0' + }, + 'device': 'bridge', + 'type': 'interface', + } + conf['devices'].append(nic2) + nic3 = { + 'nicModel': 'pv', + 'macAddr': '02:50:56:3f:c4:c0', + 'linkActive': 'true', + 'network': 'nfs', + 'filter': 'vdsm-no-mac-spoofing', + 'specParams': {}, + 'deviceId': str(uuid.uuid4()), + 'address': { + 'bus': '0x00', + 'slot': '0x0c', + 'domain': '0x0000', + 'type': 'pci', + 'function': '0x0' + }, + 'device': 'bridge', + 'type': 'interface', + } + conf['devices'].append(nic3) cli = self.environment[ohostedcons.VDSMEnv.VDS_CLI] status = cli.create(conf) ************************************************************************************ Obviously this is a horrible ad-hoc hack that I'm not able to generalize/clean-up now: doing so would involve (apart from a deeper understanding of the whole setup code/workflow) some well-thought-out design decisions and, given the effective deprecation of the aforementioned easy-to-modify vm.conf.in template substituted by hardwired Python program logic, it seems that such a functionality is not very high on the development priority list atm ;) Many thanks again! Kind regards, Giuseppe >> Many thanks in advance. >> >> Kind regards, >> Giuseppe >> >> PS: please keep also my address in replying because I'm experiencing some problems between Hotmail and oVirt-mailing-list >> >> _______________________________________________ >> Users mailing list >> Users(a)ovirt.org >> http://lists.ovirt.org/mailman/listinfo/users >>

2 2

Problem with Adding Pre-Configured Domain
by Roger Meier 25 Nov '15

25 Nov '15

This is a multi-part message in MIME format. --------------050208060806020800020208 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit Hi All, I don't know if this is a Bug or an error on my side. At the moment, i have a oVirt 3.6 installation with two Nodes and Two Storage Server, which are configured themselfs als master/slave (solaris zfs snapshot copy from master to slave all 2 hours) Now i try to do some tests for some failure use cases like, master storage isn't available anymore or one of the virtual machines must be restored from the snapshot. Because the data n the slave is a snapshot copy, all data which are on the Data Domain NFS Storage, are also on the slave NFS Storage. I tried it to add over WebUI over the option "Import Domain" (Import Pre-Configured Domain) with both Domain Functions (Data and Export) but nothing happens, expect some errors in the vdsm.log Logfile. Something like this Thread-253746::ERROR::2015-11-24 11:44:41,758::hsm::2549::Storage.HSM::(disconnectStorageServer) Could not disconnect from storageServer Traceback (most recent call last): File "/usr/share/vdsm/storage/hsm.py", line 2545, in disconnectStorageServer conObj.disconnect() File "/usr/share/vdsm/storage/storageServer.py", line 425, in disconnect return self._mountCon.disconnect() File "/usr/share/vdsm/storage/storageServer.py", line 254, in disconnect self._mount.umount(True, True) File "/usr/share/vdsm/storage/mount.py", line 256, in umount return self._runcmd(cmd, timeout) File "/usr/share/vdsm/storage/mount.py", line 241, in _runcmd raise MountError(rc, ";".join((out, err))) MountError: (32, ';umount: /rhev/data-center/mnt/192.168.1.13:_oi-srv2-sasData1_oi-srv1-sasData1_nfsshare1: mountpoint not found\n') I checked with nfs-check.py if all permissions are ok, the tool say this: Konsole output [root@lin-ovirt1 contrib]# python ./nfs-check.py 192.168.1.13:/oi-srv2-sasData1/oi-srv1-sasData1/nfsshare1 Current hostname: lin-ovirt1 - IP addr 192.168.1.14 Trying to /bin/mount -t nfs 192.168.1.13:/oi-srv2-sasData1/oi-srv1-sasData1/nfsshare1... Executing NFS tests.. Removing vdsmTest file.. Status of tests [OK] Disconnecting from NFS Server.. Done! Greetings Roger Meier --------------050208060806020800020208 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit <html> <head> <meta http-equiv="content-type" content="text/html; charset=utf-8"> </head> <body text="#000000" bgcolor="#FFFFFF"> Hi All, I don't know if this is a Bug or an error on my side. At the moment, i have a oVirt 3.6 installation with two Nodes and Two Storage Server, which are configured themselfs als master/slave (solaris zfs snapshot copy from master to slave all 2 hours) Now i try to do some tests for some failure use cases like, master storage isn't available anymore or one of the virtual machines must be restored from the snapshot. Because the data n the slave is a snapshot copy, all data which are on the Data Domain NFS Storage, are also on the slave NFS Storage. I tried it to add over WebUI over the option "Import Domain" (Import Pre-Configured Domain) with both Domain Functions (Data and Export) but nothing happens, expect some errors in the vdsm.log Logfile. Something like this Thread-253746::ERROR::2015-11-24 11:44:41,758::hsm::2549::Storage.HSM::(disconnectStorageServer) Could not disconnect from storageServer Traceback (most recent call last): File "/usr/share/vdsm/storage/hsm.py", line 2545, in disconnectStorageServer conObj.disconnect() File "/usr/share/vdsm/storage/storageServer.py", line 425, in disconnect return self._mountCon.disconnect() File "/usr/share/vdsm/storage/storageServer.py", line 254, in disconnect self._mount.umount(True, True) File "/usr/share/vdsm/storage/mount.py", line 256, in umount return self._runcmd(cmd, timeout) File "/usr/share/vdsm/storage/mount.py", line 241, in _runcmd raise MountError(rc, ";".join((out, err))) MountError: (32, ';umount: /rhev/data-center/mnt/192.168.1.13:_oi-srv2-sasData1_oi-srv1-sasData1_nfsshare1: mountpoint not found\n') I checked with nfs-check.py if all permissions are ok, the tool say this: <title>Konsole output</title> <div> [root@lin-ovirt1 contrib]# python ./nfs-check.py 192.168.1.13:/oi-srv2-sasData1/oi-srv1-sasData1/nfsshare1 Current hostname: lin-ovirt1 - IP addr 192.168.1.14 Trying to /bin/mount -t nfs 192.168.1.13:/oi-srv2-sasData1/oi-srv1-sasData1/nfsshare1... Executing NFS tests.. Removing vdsmTest file.. Status of tests [OK] Disconnecting from NFS Server.. Done! </div> <meta http-equiv="Content-Type" content="text/html; charset=utf-8"> Greetings Roger Meier </body> </html> --------------050208060806020800020208--

2 2

Move cluster between datacenters
by Dael Maselli 25 Nov '15

25 Nov '15

Hello, I have an environment with two data centers with some clusters in each one. Each cluster has one or more dedicated FC storage domains. We have some management problem because adding storage to one cluster means to add it to all nodes of all clusters in the same data center, by the way I found this a little overkill and I think it should be managed like networks. Anyway, to resolve out problems we would like to create a new datacenter and move a cluster from old data center to the new one, obviously with it's own storage domain. Is there a way to do this without export/import all vms? Thank you. Regards, Dael Maselli. -- ___________________________________________________________________ Dael Maselli --- INFN-LNF Computing Service -- +39.06.9403.2214 ___________________________________________________________________ * http://www.lnf.infn.it/~dmaselli/ * ___________________________________________________________________ Democracy is two wolves and a lamb voting on what to have for lunch ___________________________________________________________________

2 1

oVirt 4.0 wishlist: oVirt Node
by Giuseppe Ragusa 25 Nov '15

25 Nov '15

Hi all, I'm trying to organize my wishes/hopes for oVirt 4.0 These items derive from both solitary mumblings and community talks at the the first Italian oVirt Meetup. I offer to help in coding (work/family schedules permitting) but keep in mind that I'm a sysadmin with mainly C and bash-scripting skills (but hoping to improve my less-than-newbie Python too...) Since I have related interests/wishes also for Engine and VDSM, I'll send a separate message for each one. Let's start from the oVirt Node: *) oVirt Node complete convergence with Atomic Host: start from Project Atomic tools and define an ISO-installable Atomic Host variant [1] to include gluster, qemu, libvirt, vdsm and all the packages/configurations that an oVirt Node would need (remove unneeded parts) *) add Samba, CTDB and Ganesha to oVirt Node to allow it to be used as a full storage appliance (specifically, I'm thinking of the GlusterFS integration); there are related wishlist items on configuring/managing Samba/CTDB/Ganesha on the Engine and on VDSM *) add oVirt Node ability to host containers (independent of the above mentioned convergence with Atomic); note that Atomic Host has Docker/Kubernetes, but libvirt already has a LXC driver [2] and the Engine could benefit from some added smartness in managing groups of guests etc. in the vm case too; there are related wishlist items on configuring/managing containers on the Engine and on VDSM *) add Open vSwitch direct support (not Neutron-mediated); there are related wishlist items on configuring/managing Open vSwitch on the Engine and on VDSM *) add DRBD9 as a supported Storage Domain type, maybe for HC and HE too; there are related wishlist items on configuring/managing DRBD9 on the Engine and on VDSM *) add oVirt Node ability to fully perform as a stand-alone hypervisor: I hear that Cockpit is coming, so why not Kimchi too? ;) Regards, Giuseppe [1] product.json, I suppose, but I'm starting to learn Atomic now... [2] barring a pending deprecation in RHEL7, but I suppose that a community/Centos-Virt-SIG libvirt build could restore it and maybe RedHat too could support it on a special libvirt build for RHEV (just to remove those support costs from the base RHEL OS offering)

3 2

[OT] Gmail is marking the list as spam.
by Juan Pablo Lorier 25 Nov '15

25 Nov '15

Hi, Someone may take a look at the spam policy of Gmail to see what is not been done as it's been months since I have to get the mails from spam folder no matter how much I try to get them as legitime. Regards El 22/10/15 a las 12:24 p.m., users-request(a)ovirt.org escribió: > Send Users mailing list submissions to > users(a)ovirt.org > > To subscribe or unsubscribe via the World Wide Web, visit > http://lists.ovirt.org/mailman/listinfo/users > or, via email, send a message with subject or body 'help' to > users-request(a)ovirt.org > > You can reach the person managing the list at > users-owner(a)ovirt.org > > When replying, please edit your Subject line so it is more specific > than "Re: Contents of Users digest..." > > > Today's Topics: > > 1. [ANN] oVirt 3.6.0 Third Release Candidate is now available > for testing (Sandro Bonazzola) > 2. Re: Testing self hosted engine in 3.6: hostname not resolved > error (Gianluca Cecchi) > 3. Re: 3.6 upgrade issue (Yaniv Dary) > 4. Re: How to change the hosted engine VM RAM size after > deploying (Simone Tiraboschi) > > > ---------------------------------------------------------------------- > > Message: 1 > Date: Thu, 22 Oct 2015 16:08:25 +0200 > From: Sandro Bonazzola <sbonazzo(a)redhat.com> > To: announce(a)ovirt.org, users <users(a)ovirt.org>, devel > <devel(a)ovirt.org> > Subject: [ovirt-users] [ANN] oVirt 3.6.0 Third Release Candidate is > now available for testing > Message-ID: > <CAPQRNTm4GyWo0zo-L=92ScLJvWQFEPKaF5UfmdJ4SroKCCC3pQ(a)mail.gmail.com> > Content-Type: text/plain; charset="utf-8" > > The oVirt Project is pleased to announce the availability > of the Third Release Candidate of oVirt 3.6 for testing, as of October > 22nd, 2015. > > This release is available now for Fedora 22, > Red Hat Enterprise Linux 6.7, CentOS Linux 6.7 (or similar) and > Red Hat Enterprise Linux 7.1, CentOS Linux 7.1 (or similar). > > This release supports Hypervisor Hosts running > Red Hat Enterprise Linux 7.1, CentOS Linux 7.1 (or similar), > Fedora 21 and Fedora 22. > Highly experimental support for Debian 8.1 Jessie has been added too. > > This release of oVirt 3.6.0 includes numerous bug fixes. > See the release notes [1] for an initial list of the new features and bugs > fixed. > > Please refer to release notes [1] for Installation / Upgrade instructions. > New oVirt Node ISO and oVirt Live ISO will be available soon as well[2]. > > Please note that mirrors[3] may need usually one day before being > synchronized. > > Please refer to the release notes for known issues in this release. > > [1] http://www.ovirt.org/OVirt_3.6_Release_Notes > [2] http://plain.resources.ovirt.org/pub/ovirt-3.6-pre/iso/ > [3] http://www.ovirt.org/Repository_mirrors#Current_mirrors > >

3 2

Could not associate brick
by Bello Florent 24 Nov '15

24 Nov '15

--=_920b73690f5d77fd5fed2f8d20a489a7 Content-Transfer-Encoding: 7bit Content-Type: text/plain; charset=UTF-8 Hi, 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. I found in mailing list i have to put all my hosts in maintenance mode and put on. Then now engine.log chain : 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 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' 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' 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' 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' 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' 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' 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 Here my vdsm.log on host 1: 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'}] Reactor thread::INFO::2015-11-09 11:17:48,004::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57851 Reactor thread::DEBUG::2015-11-09 11:17:48,012::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:48,013::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57851 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) BindingXMLRPC::INFO::2015-11-09 11:17:48,013::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57851 Thread-4248::INFO::2015-11-09 11:17:48,015::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57851 started Thread-4248::INFO::2015-11-09 11:17:48,022::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57851 stopped 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) Thread-303::DEBUG::2015-11-09 11:17:48,154::fileSD::173::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records inn0+1 records outn461 bytes (461 B) copied, 0.000382969 s, 1.2 MB/sn'; <rc> = 0 mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:48,767::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) dd if=/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None) mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:48,783::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records inn1+0 records outn1024000 bytes (1.0 MB) copied, 0.00507258 s, 202 MB/sn'; <rc> = 0 Reactor thread::INFO::2015-11-09 11:17:49,939::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57852 Reactor thread::DEBUG::2015-11-09 11:17:49,947::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:49,947::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57852 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) BindingXMLRPC::INFO::2015-11-09 11:17:49,948::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57852 Thread-4249::INFO::2015-11-09 11:17:49,949::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57852 started Thread-4249::DEBUG::2015-11-09 11:17:49,950::bindingxmlrpc::1257::vds::(wrapper) client [127.0.0.1]::call getCapabilities with () {} Thread-4249::DEBUG::2015-11-09 11:17:49,962::netinfo::454::root::(_dhcp_used) DHCPv6 configuration not specified for ovirtmgmt. 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 Thread-4249::DEBUG::2015-11-09 11:17:49,965::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on enp2s0. Thread-4249::DEBUG::2015-11-09 11:17:49,965::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on enp2s0. Thread-4249::DEBUG::2015-11-09 11:17:49,968::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on bond0. Thread-4249::DEBUG::2015-11-09 11:17:49,968::netinfo::440::root::(_dhcp_used) There is no VDSM network configured on bond0. 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 Thread-4249::DEBUG::2015-11-09 11:17:49,971::utils::676::root::(execCmd) /usr/sbin/tc qdisc show (cwd None) Thread-4249::DEBUG::2015-11-09 11:17:49,979::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0 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) Thread-4249::DEBUG::2015-11-09 11:17:49,989::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0 Thread-4249::DEBUG::2015-11-09 11:17:49,993::caps::807::root::(_getKeyPackages) rpm package ('glusterfs-rdma',) not found Thread-4249::DEBUG::2015-11-09 11:17:49,997::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-object',) not found Thread-4249::DEBUG::2015-11-09 11:17:49,997::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-proxy',) not found Thread-4249::DEBUG::2015-11-09 11:17:50,001::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-plugin',) not found Thread-4249::DEBUG::2015-11-09 11:17:50,002::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift',) not found Thread-4249::DEBUG::2015-11-09 11:17:50,002::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-container',) not found Thread-4249::DEBUG::2015-11-09 11:17:50,003::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-account',) not found Thread-4249::DEBUG::2015-11-09 11:17:50,003::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift-doc',) not found 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'}} Thread-4249::INFO::2015-11-09 11:17:50,020::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57852 stopped mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:50,797::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) dd if=/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None) mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:50,815::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records inn1+0 records outn1024000 bytes (1.0 MB) copied, 0.00511026 s, 200 MB/sn'; <rc> = 0 Reactor thread::INFO::2015-11-09 11:17:52,098::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57853 Reactor thread::DEBUG::2015-11-09 11:17:52,106::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,107::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57853 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) BindingXMLRPC::INFO::2015-11-09 11:17:52,108::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57853 Thread-4250::INFO::2015-11-09 11:17:52,110::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57853 started Thread-4250::DEBUG::2015-11-09 11:17:52,111::bindingxmlrpc::1257::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} 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'}} Thread-4250::INFO::2015-11-09 11:17:52,114::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57853 stopped Reactor thread::INFO::2015-11-09 11:17:52,116::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57854 Reactor thread::DEBUG::2015-11-09 11:17:52,124::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,124::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57854 BindingXMLRPC::INFO::2015-11-09 11:17:52,125::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57854 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) Thread-4251::INFO::2015-11-09 11:17:52,128::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57854 started Thread-4251::DEBUG::2015-11-09 11:17:52,129::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4251::INFO::2015-11-09 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) Thread-4251::DEBUG::2015-11-09 11:17:52,132::hsm::2417::Storage.HSM::(__prefetchDomains) glusterDomPath: glusterSD/* 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') 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} Thread-4251::INFO::2015-11-09 11:17:52,147::logUtils::51::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '2c69bdcf-793b-4fda-b326-b8aa6c33ade0'}]} 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'}]} 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 Thread-4251::DEBUG::2015-11-09 11:17:52,147::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-4251::DEBUG::2015-11-09 11:17:52,148::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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 Thread-4251::INFO::2015-11-09 11:17:52,149::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57854 stopped Reactor thread::INFO::2015-11-09 11:17:52,150::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57855 Reactor thread::DEBUG::2015-11-09 11:17:52,158::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,158::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57855 BindingXMLRPC::INFO::2015-11-09 11:17:52,159::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57855 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) Thread-4255::INFO::2015-11-09 11:17:52,162::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57855 started Thread-4255::DEBUG::2015-11-09 11:17:52,162::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4255::INFO::2015-11-09 11:17:52,163::logUtils::48::dispatcher::(wrapper) Run and protect: getStorageDomainStats(sdUUID='b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', options=None) 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' 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' 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) 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 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) 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 Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method 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 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) Thread-4255::DEBUG::2015-11-09 11:17:52,183::misc::760::Storage.SamplingMethod::(__call__) Returning last result Thread-4255::DEBUG::2015-11-09 11:17:52,183::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.hba.rescan) Thread-4255::DEBUG::2015-11-09 11:17:52,184::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method Thread-4255::DEBUG::2015-11-09 11:17:52,184::hba::56::Storage.HBA::(rescan) Starting scan Thread-4255::DEBUG::2015-11-09 11:17:52,295::hba::62::Storage.HBA::(rescan) Scan finished Thread-4255::DEBUG::2015-11-09 11:17:52,296::misc::760::Storage.SamplingMethod::(__call__) Returning last result 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) Thread-4255::DEBUG::2015-11-09 11:17:52,362::multipath::77::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 Thread-4255::DEBUG::2015-11-09 11:17:52,362::utils::676::root::(execCmd) /sbin/udevadm settle --timeout=5 (cwd None) Thread-4255::DEBUG::2015-11-09 11:17:52,371::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0 Thread-4255::DEBUG::2015-11-09 11:17:52,372::lvm::498::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,372::lvm::500::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::509::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::511::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::529::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::531::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,374::misc::760::Storage.SamplingMethod::(__call__) Returning last result 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 Thread-4255::DEBUG::2015-11-09 11:17:52,387::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend 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'] Thread-4255::DEBUG::2015-11-09 11:17:52,398::fileSD::647::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images [] Thread-4255::INFO::2015-11-09 11:17:52,399::sd::442::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace b4c488af-9d2f-4b7b-a6f6-74a0bac06c41_imageNS already registered Thread-4255::INFO::2015-11-09 11:17:52,399::sd::450::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace b4c488af-9d2f-4b7b-a6f6-74a0bac06c41_volumeNS already registered Thread-4255::INFO::2015-11-09 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}} 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}} 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 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'>} Thread-4255::DEBUG::2015-11-09 11:17:52,401::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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' 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) 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. 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. 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 Thread-4255::INFO::2015-11-09 11:17:52,404::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57855 stopped Reactor thread::INFO::2015-11-09 11:17:52,405::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57856 Reactor thread::DEBUG::2015-11-09 11:17:52,413::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,414::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57856 BindingXMLRPC::INFO::2015-11-09 11:17:52,414::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57856 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) Thread-4259::INFO::2015-11-09 11:17:52,417::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57856 started Thread-4259::DEBUG::2015-11-09 11:17:52,418::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4259::INFO::2015-11-09 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') 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' 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' 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) 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 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) 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 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 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 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 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 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 Thread-4259::DEBUG::2015-11-09 11:17:52,448::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 8f8ee034-de86-4438-b6eb-9109faa8b3d3 Thread-4259::INFO::2015-11-09 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'}]} 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'}]} 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 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'>} Thread-4259::DEBUG::2015-11-09 11:17:52,450::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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' 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) 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. 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. 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 Thread-4259::INFO::2015-11-09 11:17:52,454::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57856 stopped Reactor thread::INFO::2015-11-09 11:17:52,454::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57857 Reactor thread::DEBUG::2015-11-09 11:17:52,463::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,463::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57857 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) BindingXMLRPC::INFO::2015-11-09 11:17:52,464::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57857 Thread-4260::INFO::2015-11-09 11:17:52,466::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57857 started Thread-4260::DEBUG::2015-11-09 11:17:52,467::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4260::INFO::2015-11-09 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') 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' 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' 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) 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 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) 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 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 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 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 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 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 Thread-4260::DEBUG::2015-11-09 11:17:52,488::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 8bb29fcb-c109-4f0a-a227-3819b6ecfdd9 Thread-4260::INFO::2015-11-09 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'}]} 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'}]} 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 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'>} Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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' 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) 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. 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. 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 Thread-4260::INFO::2015-11-09 11:17:52,494::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57857 stopped Reactor thread::INFO::2015-11-09 11:17:52,494::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57858 Reactor thread::DEBUG::2015-11-09 11:17:52,503::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,504::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57858 BindingXMLRPC::INFO::2015-11-09 11:17:52,504::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57858 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) Thread-4261::INFO::2015-11-09 11:17:52,507::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57858 started Thread-4261::DEBUG::2015-11-09 11:17:52,508::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4261::INFO::2015-11-09 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') 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' 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' 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) 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 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) 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 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 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 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 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 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 Thread-4261::DEBUG::2015-11-09 11:17:52,530::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 3fc3362d-ab6d-4e06-bd72-82d5750c7095 Thread-4261::INFO::2015-11-09 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'}]} 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'}]} 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 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'>} Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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' 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) 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. 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. 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 Thread-4261::INFO::2015-11-09 11:17:52,535::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57858 stopped Reactor thread::INFO::2015-11-09 11:17:52,536::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57859 Reactor thread::DEBUG::2015-11-09 11:17:52,544::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,545::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57859 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) BindingXMLRPC::INFO::2015-11-09 11:17:52,545::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57859 Thread-4262::INFO::2015-11-09 11:17:52,548::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57859 started Thread-4262::DEBUG::2015-11-09 11:17:52,548::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4262::INFO::2015-11-09 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') 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' 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' 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) 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 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) 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 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 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 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 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 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 Thread-4262::DEBUG::2015-11-09 11:17:52,570::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for 02c5d59d-638c-4672-814d-d734e334e24a Thread-4262::INFO::2015-11-09 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'}]} 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'}]} 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 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'>} Thread-4262::DEBUG::2015-11-09 11:17:52,573::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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' 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) 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. 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. 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 Thread-4262::INFO::2015-11-09 11:17:52,576::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57859 stopped Reactor thread::INFO::2015-11-09 11:17:52,610::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127.0.0.1:57860 Reactor thread::DEBUG::2015-11-09 11:17:52,619::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=11 Reactor thread::INFO::2015-11-09 11:17:52,619::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127.0.0.1:57860 BindingXMLRPC::INFO::2015-11-09 11:17:52,620::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:57860 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) Thread-4263::INFO::2015-11-09 11:17:52,623::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57860 started Thread-4263::DEBUG::2015-11-09 11:17:52,623::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] 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 Thread-4263::INFO::2015-11-09 11:17:52,624::logUtils::48::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-4263::INFO::2015-11-09 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}} 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}} 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 Thread-4263::DEBUG::2015-11-09 11:17:52,625::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-4263::DEBUG::2015-11-09 11:17:52,625::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} 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 Thread-4263::INFO::2015-11-09 11:17:52,627::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57860 stopped mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:52,829::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) dd if=/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None) mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:52,845::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records inn1+0 records outn1024000 bytes (1.0 MB) copied, 0.00494757 s, 207 MB/sn'; <rc> = 0 -- Florent BELLO Service Informatique informatique(a)ville-kourou.fr 0594 22 31 22 Mairie de Kourou --=_920b73690f5d77fd5fed2f8d20a489a7 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=UTF-8 <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN"> <html><body> Hi, 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= =2E I found in mailing list i have to put all my hosts in maintenance = mode and put on. Then now engine.log chain : 2015-11-09 11:15:53,563 INFO  [org.ovirt.engine.core.vdsbroker.glus= ter.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler_Worker-64) [] STA= RT, GlusterVolumesListVDSCommand(HostName =3D ovirt02, GlusterVolumesListVD= SParameters:{runAsync=3D'true', hostId=3D'0d1284e1-fa18-4309-b196-df9a6a337= c44'}), log id: 6ddd5b9d 2015-11-09 11:15:53,711 WARN  [org.ovirt= =2Eengine.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (Defaul= tQuartzScheduler_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' 2015-11-09 11:15:53,714 WARN  [org.ovirt.engin= e.core.vdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzS= cheduler_Worker-64) [] Could not associate brick 'ovirt02.mafia.kru:/gfs1/e= ngine/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct = network as no gluster network found in cluster '00000002-0002-0002-0002-000= 00000022d' 2015-11-09 11:15:53,716 WARN  [org.ovirt.engine.core= =2Evdsbroker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzSched= uler_Worker-64) [] Could not associate brick 'ovirt03.mafia.kru:/gfs1/engin= e/brick' of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct netw= ork as no gluster network found in cluster '00000002-0002-0002-0002-0000000= 0022d' 2015-11-09 11:15:53,719 WARN  [org.ovirt.engine.core.vdsbr= oker.gluster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Wor= ker-64) [] Could not associate brick 'ovirt01.mafia.kru:/gfs2/engine/brick'= of volume 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as n= o gluster network found in cluster '00000002-0002-0002-0002-00000000022d'<b= r />2015-11-09 11:15:53,722 WARN  [org.ovirt.engine.core.vdsbroker.glu= ster.GlusterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) = [] Could not associate brick 'ovirt02.mafia.kru:/gfs2/engine/brick' of volu= me 'e9a24161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluste= r network found in cluster '00000002-0002-0002-0002-00000000022d' 2015= -11-09 11:15:53,725 WARN  [org.ovirt.engine.core.vdsbroker.gluster.Glu= sterVolumesListReturnForXmlRpc] (DefaultQuartzScheduler_Worker-64) [] Could= not associate brick 'ovirt03.mafia.kru:/gfs2/engine/brick' of volume 'e9a2= 4161-3e72-47ea-b593-57f3302e7c4e' with correct network as no gluster networ= k found in cluster '00000002-0002-0002-0002-00000000022d' 2015-11-09 1= 1:15:53,732 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolu= mesListVDSCommand] (DefaultQuartzScheduler_Worker-64) [] FINISH, GlusterVol= umesListVDSCommand, return: {e9a24161-3e72-47ea-b593-57f3302e7c4e=3Dorg.ovi= rt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7eafe244= , e5df896f-b818-4d70-ac86-ad9270f9d5f2=3Dorg.ovirt.engine.core.common.busin= essentities.gluster.GlusterVolumeEntity@cb7d0349}, log id: 6ddd5b9d   Here my vdsm.log on host 1: Thread-4247::DEBUG::2015-11-09 11:17:47,621::__init__::533::jsonrpc.Json= RpcServer::(_serveRequest) Return 'Host.getVMFullList' in bridge with [{u's= tatus': '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'ab= 824f92-f636-4c0f-96ad-b4f3d1c352be', u'device': u'console', u'type': u'cons= ole'}, {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'chan= nel', 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't= ype': 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'con= troller', u'address': {u'slot': u'0x04', u'bus': u'0x00', u'domain': u'0x00= 00', 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'usb= 0', 'deviceType': u'controller', u'type': u'controller', u'address': {u'slo= t': u'0x01', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'func= tion': u'0x2'}}, {u'device': u'ide', u'alias': u'ide0', 'deviceType': u'con= troller', 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'dev= ice': u'virtio-serial', u'alias': u'virtio-serial0', 'deviceType': u'contro= ller', u'type': u'controller', u'address': {u'slot': u'0x05', u'bus': u'0x0= 0', 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'a= ddress': {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'spice= SecureChannels': u'smain,sdisplay,sinputs,scursor,splayback,srecord,ssmartc= ard,susbredir', u'displayIp': '0'}, 'deviceType': u'graphics', u'type': u'g= raphics', 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'inte= rface', 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': {'dom= ainID': u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseO= ffset': 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/8f8ee03= 4-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'ifa= ce': u'virtio', u'apparentsize': '26843545600', u'specParams': {}, u'imageI= D': u'56461302-0710-4df0-964d-5e7b1ff07828', u'readonly': 'False', 'deviceT= ype': 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-5e7b1ff078= 28', 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-96= 4d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3', u'propagateErrors': = u'off', u'optional': u'false', u'name': u'vda', u'bootOrder': u'1', u'volum= eID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', u'alias': u'virtio-disk0', u= 'volumeChain': [{'domainID': u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volT= ype': 'path', 'leaseOffset': 0, 'volumeID': u'8f8ee034-de86-4438-b6eb-9109f= aa8b3d3', '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'564= 61302-0710-4df0-964d-5e7b1ff07828', 'path': u'/rhev/data-center/mnt/gluster= SD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56= 461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d3'}]}= ], u'guestDiskMapping': {}, u'spiceSecureChannels': u'smain,sdisplay,sinput= s,scursor,splayback,srecord,ssmartcard,susbredir', u'vmType': u'kvm', u'dis= playIp': '0', u'displaySecurePort': '-1', u'memSize': 1536, u'displayPort':= u'5900', u'cpuType': u'Conroe', 'clientIp': u'', u'statusTime': '429970492= 0', u'vmName': u'HostedEngine', u'display': 'vnc'}] Reactor thread::IN= FO::2015-11-09 11:17:48,004::protocoldetector::72::ProtocolDetector.Accepto= rImpl::(handle_accept) Accepting connection from 127.0.0.1:57851 React= or thread::DEBUG::2015-11-09 11:17:48,012::protocoldetector::82::ProtocolDe= tector.Detector::(__init__) Using required_size=3D11 Reactor thread::I= NFO::2015-11-09 11:17:48,013::protocoldetector::118::ProtocolDetector.Detec= tor::(handle_read) Detected protocol xml from 127.0.0.1:57851 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) Bindin= gXMLRPC::INFO::2015-11-09 11:17:48,013::xmlrpc::73::vds.XMLRPCServer::(hand= le_request) Starting request handler for 127.0.0.1:57851 Thread-4248::= INFO::2015-11-09 11:17:48,015::xmlrpc::84::vds.XMLRPCServer::(_process_requ= ests) Request handler for 127.0.0.1:57851 started Thread-4248::INFO::2= 015-11-09 11:17:48,022::xmlrpc::92::vds.XMLRPCServer::(_process_requests) R= equest handler for 127.0.0.1:57851 stopped Thread-303::DEBUG::2015-11-= 09 11:17:48,143::fileSD::173::Storage.Misc.excCmd::(getReadDelay) /usr/bin/= dd if=3D/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_data/0af99439-f1= 40-4636-90f7-f43904735da0/dom_md/metadata iflag=3Ddirect of=3D/dev/null bs= =3D4096 count=3D1 (cwd None) Thread-303::DEBUG::2015-11-09 11:17:48,15= 4::fileSD::173::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = =3D '0+1 records in\n0+1 records out\n461 bytes (461 B) copied, 0.000382969= s, 1.2 MB/s\n'; <rc> =3D 0 mailbox.SPMMonitor::DEBUG::2015-11-0= 9 11:17:48,767::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) = dd if=3D/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom= _md/inbox iflag=3Ddirect,fullblock count=3D1 bs=3D1024000 (cwd None) m= ailbox.SPMMonitor::DEBUG::2015-11-09 11:17:48,783::storage_mailbox::735::St= orage.Misc.excCmd::(_checkForMail) SUCCESS: <err> =3D '1+0 records in= \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.00507258 s, 202 MB/s\n'= ; <rc> =3D 0 Reactor thread::INFO::2015-11-09 11:17:49,939::prot= ocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting = connection from 127.0.0.1:57852 Reactor thread::DEBUG::2015-11-09 11:1= 7:49,947::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using= required_size=3D11 Reactor thread::INFO::2015-11-09 11:17:49,947::pro= tocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected proto= col xml from 127.0.0.1:57852 Reactor thread::DEBUG::2015-11-09 11:17:4= 9,947::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http dete= cted from ('127.0.0.1', 57852) BindingXMLRPC::INFO::2015-11-09 11:17:4= 9,948::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request hand= ler for 127.0.0.1:57852 Thread-4249::INFO::2015-11-09 11:17:49,949::xm= lrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0= =2E0.1:57852 started Thread-4249::DEBUG::2015-11-09 11:17:49,950::bind= ingxmlrpc::1257::vds::(wrapper) client [127.0.0.1]::call getCapabilities wi= th () {} Thread-4249::DEBUG::2015-11-09 11:17:49,962::netinfo::454::ro= ot::(_dhcp_used) DHCPv6 configuration not specified for ovirtmgmt. Thr= ead-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 Thre= ad-4249::DEBUG::2015-11-09 11:17:49,965::netinfo::440::root::(_dhcp_used) T= here is no VDSM network configured on enp2s0. Thread-4249::DEBUG::2015= -11-09 11:17:49,965::netinfo::440::root::(_dhcp_used) There is no VDSM netw= ork configured on enp2s0. Thread-4249::DEBUG::2015-11-09 11:17:49,968:= :netinfo::440::root::(_dhcp_used) There is no VDSM network configured on bo= nd0. Thread-4249::DEBUG::2015-11-09 11:17:49,968::netinfo::440::root::= (_dhcp_used) There is no VDSM network configured on bond0. Thread-4249= ::DEBUG::2015-11-09 11:17:49,970::netinfo::686::root::(_get_gateway) The ga= teway 10.10.10.254 is duplicated for the device ovirtmgmt Thread-4249:= :DEBUG::2015-11-09 11:17:49,971::utils::676::root::(execCmd) /usr/sbin/tc q= disc show (cwd None) Thread-4249::DEBUG::2015-11-09 11:17:49,979::util= s::694::root::(execCmd) SUCCESS: <err> =3D ''; <rc> =3D 0 = Thread-4249::DEBUG::2015-11-09 11:17:49,980::utils::676::root::(execCmd) /u= sr/sbin/tc class show dev enp2s0 classid 0:1388 (cwd None) Thread-4249= ::DEBUG::2015-11-09 11:17:49,989::utils::694::root::(execCmd) SUCCESS: <= err> =3D ''; <rc> =3D 0 Thread-4249::DEBUG::2015-11-09 11:17:= 49,993::caps::807::root::(_getKeyPackages) rpm package ('glusterfs-rdma',) = not found Thread-4249::DEBUG::2015-11-09 11:17:49,997::caps::807::root= ::(_getKeyPackages) rpm package ('gluster-swift-object',) not found Th= read-4249::DEBUG::2015-11-09 11:17:49,997::caps::807::root::(_getKeyPackage= s) rpm package ('gluster-swift-proxy',) not found Thread-4249::DEBUG::= 2015-11-09 11:17:50,001::caps::807::root::(_getKeyPackages) rpm package ('g= luster-swift-plugin',) not found Thread-4249::DEBUG::2015-11-09 11:17:= 50,002::caps::807::root::(_getKeyPackages) rpm package ('gluster-swift',) n= ot found Thread-4249::DEBUG::2015-11-09 11:17:50,002::caps::807::root:= :(_getKeyPackages) rpm package ('gluster-swift-container',) not found = Thread-4249::DEBUG::2015-11-09 11:17:50,003::caps::807::root::(_getKeyPacka= ges) rpm package ('gluster-swift-account',) not found Thread-4249::DEB= UG::2015-11-09 11:17:50,003::caps::807::root::(_getKeyPackages) rpm package= ('gluster-swift-doc',) not found 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': []}, 'pa= ckages2': {'kernel': {'release': '229.20.1.el7.x86_64', 'buildtime': 144658= 8607.0, 'version': '3.10.0'}, 'glusterfs-fuse': {'release': '1.el7', 'build= time': 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': {'relea= se': '0.el7.centos', 'buildtime': 1446474396L, 'version': '4.17.10.1'}, 'qe= mu-kvm': {'release': '29.1.el7', 'buildtime': 1444310806L, 'version': '2.3= =2E0'}, 'glusterfs': {'release': '1.el7', 'buildtime': 1444235292L, 'versio= n': '3.7.5'}, 'libvirt': {'release': '16.el7_1.5', 'buildtime': 1446559281L= , 'version': '1.2.8'}, 'qemu-img': {'release': '29.1.el7', 'buildtime': 144= 4310806L, 'version': '2.3.0'}, 'mom': {'release': '2.el7', 'buildtime': 144= 2501481L, 'version': '0.5.1'}, 'glusterfs-geo-replication': {'release': '1= =2Eel7', 'buildtime': 1444235292L, 'version': '3.7.5'}, 'glusterfs-server':= {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7.5'}, 'glust= erfs-cli': {'release': '1.el7', 'buildtime': 1444235292L, 'version': '3.7= =2E5'}}, 'numaNodeDistance': {'0': [10]}, 'cpuModel': 'Intel(R) Core(TM)2 Q= uad CPU    Q8400  @ 2.66GHz', 'liveMerge': 'true', 'hoo= ks': {'before_vm_start': {'50_hostedengine': {'md5': '2a6d96c26a3599812be6c= f1a13d9f485'}}}, 'vmTypes': ['kvm'], 'selinux': {'mode': '-1'}, 'liveSnapsh= ot': 'true', 'kdumpStatus': 0, 'networks': {'ovirtmgmt': {'iface': 'ovirtmg= mt', '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': 'no= ne', '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': F= alse, 'stp': 'off', 'ipv4addrs': ['10.10.10.211/24'], 'mtu': '1500', 'ipv6g= ateway': '::', 'ports': ['vnet0', 'enp2s0']}}, 'bridges': {'ovirtmgmt': {'a= ddr': '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', 'S= TP': 'off', 'DEVICE': 'ovirtmgmt', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'ipv= 6addrs': ['fe80::6e62:6dff:feb3:3b72/64'], 'gateway': '10.10.10.254', 'dhcp= v4': False, 'netmask': '255.255.255.0', 'dhcpv6': False, 'stp': 'off', 'ipv= 4addrs': ['10.10.10.211/24'], 'mtu': '1500', 'ipv6gateway': '::', 'ports': = ['vnet0', 'enp2s0'], 'opts': {'multicast_last_member_count': '2', 'hash_ela= sticity': '4', 'multicast_query_response_interval': '1000', 'group_fwd_mask= ': '0x0', 'multicast_snooping': '1', 'multicast_startup_query_interval': '3= 125', '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_sta= rtup_query_count': '2', 'nf_call_iptables': '0', 'topology_change': '0', 'h= ello_time': '200', 'root_id': '8000.6c626db33b72', 'bridge_id': '8000.6c626= db33b72', 'topology_change_timer': '0', 'ageing_time': '30000', 'nf_call_ip= 6tables': '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_rout= er': '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, 'ipv4= addrs': [], 'cfg': {'BRIDGE': 'ovirtmgmt', 'IPV6INIT': 'no', 'NM_CONTROLLED= ': 'no', 'HWADDR': '6c:62:6d:b3:3b:72', 'BOOTPROTO': 'none', 'DEVICE': 'enp= 2s0', 'ONBOOT': 'yes'}, 'hwaddr': '6c:62:6d:b3:3b:72', 'speed': 1000, 'gate= way': ''}}, 'software_revision': '0', 'hostdevPassthrough': 'false', 'clust= erLevels': ['3.4', '3.5', '3.6'], 'cpuFlags': 'fpu,vme,de,pse,tsc,msr,pae,m= ce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,s= se2,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': 'iq= n.1994-05.com.redhat:1954deeb7a38', 'netConfigDirty': 'False', 'supportedEN= GINEs': ['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': [], 'h= waddr': '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]}}, 'cpuSock= ets': '1', 'vlans': {}, 'lastClientIface': 'lo', 'cpuCores': '4', 'kvmEnabl= ed': 'true', 'guestOverhead': '65', 'version_name': 'Snow Man', 'cpuThreads= ': '4', 'emulatedMachines': ['pc-i440fx-rhel7.1.0', 'rhel6.3.0', 'pc-q35-rh= el7.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', 'r= hel6.4.0', 'rhel6.0.0', 'rhel6.5.0'], 'rngSources': ['random'], 'operatingS= ystem': {'release': '1.1503.el7.centos.2.8', 'version': '7', 'name': 'RHEL'= }, 'lastClient': '127.0.0.1'}} Thread-4249::INFO::2015-11-09 11:17:50,= 020::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for = 127.0.0.1:57852 stopped mailbox.SPMMonitor::DEBUG::2015-11-09 11:17:50= ,797::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) dd if=3D/r= hev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_md/inbox = iflag=3Ddirect,fullblock count=3D1 bs=3D1024000 (cwd None) mailbox.SPM= Monitor::DEBUG::2015-11-09 11:17:50,815::storage_mailbox::735::Storage.Misc= =2EexcCmd::(_checkForMail) SUCCESS: <err> =3D '1+0 records in\n1+0 re= cords out\n1024000 bytes (1.0 MB) copied, 0.00511026 s, 200 MB/s\n'; <rc= > =3D 0 Reactor thread::INFO::2015-11-09 11:17:52,098::protocoldete= ctor::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connecti= on from 127.0.0.1:57853 Reactor thread::DEBUG::2015-11-09 11:17:52,106= ::protocoldetector::82::ProtocolDetector.Detector::(__init__) Using require= d_size=3D11 Reactor thread::INFO::2015-11-09 11:17:52,107::protocoldet= ector::118::ProtocolDetector.Detector::(handle_read) Detected protocol xml = from 127.0.0.1:57853 Reactor thread::DEBUG::2015-11-09 11:17:52,107::b= indingxmlrpc::1297::XmlDetector::(handle_socket) xml over http detected fro= m ('127.0.0.1', 57853) BindingXMLRPC::INFO::2015-11-09 11:17:52,108::x= mlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for = 127.0.0.1:57853 Thread-4250::INFO::2015-11-09 11:17:52,110::xmlrpc::84= ::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57853= started Thread-4250::DEBUG::2015-11-09 11:17:52,111::bindingxmlrpc::1= 257::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-4250::DEBUG::2015-11-09 11:17:52,112::bindingxmlrpc::1264::vds::(w= rapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': = 0}, 'info': {'systemProductName': 'MS-7529', 'systemSerialNumber': 'To Be F= illed By O.E.M.', 'systemFamily': 'To Be Filled By O.E.M.', 'systemVersion'= : '1.0', 'systemUUID': '00000000-0000-0000-0000-6C626DB33B72', 'systemManuf= acturer': 'MICRO-STAR INTERNATIONAL CO.,LTD'}} Thread-4250::INFO::2015= -11-09 11:17:52,114::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Requ= est handler for 127.0.0.1:57853 stopped Reactor thread::INFO::2015-11-= 09 11:17:52,116::protocoldetector::72::ProtocolDetector.AcceptorImpl::(hand= le_accept) Accepting connection from 127.0.0.1:57854 Reactor thread::D= EBUG::2015-11-09 11:17:52,124::protocoldetector::82::ProtocolDetector.Detec= tor::(__init__) Using required_size=3D11 Reactor thread::INFO::2015-11= -09 11:17:52,124::protocoldetector::118::ProtocolDetector.Detector::(handle= _read) Detected protocol xml from 127.0.0.1:57854 BindingXMLRPC::INFO:= :2015-11-09 11:17:52,125::xmlrpc::73::vds.XMLRPCServer::(handle_request) St= arting request handler for 127.0.0.1:57854 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) Thread-4251::INFO::2015-1= 1-09 11:17:52,128::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Reques= t handler for 127.0.0.1:57854 started Thread-4251::DEBUG::2015-11-09 1= 1:17:52,129::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] Thr= ead-4251::DEBUG::2015-11-09 11:17:52,130::task::595::Storage.TaskManager.Ta= sk::(_updateState) Task=3D`8535d95e-dce6-4474-bd8d-7824f68cf68a`::moving fr= om state init -> state preparing Thread-4251::INFO::2015-11-09 11:1= 7:52,130::logUtils::48::dispatcher::(wrapper) Run and protect: connectStora= geServer(domType=3D7, spUUID=3D'00000000-0000-0000-0000-000000000000', conL= ist=3D[{'id': '2c69bdcf-793b-4fda-b326-b8aa6c33ade0', 'vfs_type': 'glusterf= s', 'connection': 'ovirt02.mafia.kru:/engine', 'user': 'kvm'}], options=3DN= one) Thread-4251::DEBUG::2015-11-09 11:17:52,132::hsm::2417::Storage= =2EHSM::(__prefetchDomains) glusterDomPath: glusterSD/* Thread-4251::D= EBUG::2015-11-09 11:17:52,146::hsm::2429::Storage.HSM::(__prefetchDomains) = Found SD uuids: (u'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', u'0af99439-f140-4= 636-90f7-f43904735da0') Thread-4251::DEBUG::2015-11-09 11:17:52,147::h= sm::2489::Storage.HSM::(connectStorageServer) knownSDs: {b4c488af-9d2f-4b7b= -a6f6-74a0bac06c41: storage.glusterSD.findDomain, 0af99439-f140-4636-90f7-f= 43904735da0: storage.glusterSD.findDomain} Thread-4251::INFO::2015-11-= 09 11:17:52,147::logUtils::51::dispatcher::(wrapper) Run and protect: conne= ctStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '2c69= bdcf-793b-4fda-b326-b8aa6c33ade0'}]} Thread-4251::DEBUG::2015-11-09 11= :17:52,147::task::1191::Storage.TaskManager.Task::(prepare) Task=3D`8535d95= e-dce6-4474-bd8d-7824f68cf68a`::finished: {'statuslist': [{'status': 0, 'id= ': '2c69bdcf-793b-4fda-b326-b8aa6c33ade0'}]} Thread-4251::DEBUG::2015-= 11-09 11:17:52,147::task::595::Storage.TaskManager.Task::(_updateState) Tas= k=3D`8535d95e-dce6-4474-bd8d-7824f68cf68a`::moving from state preparing -&g= t; state finished Thread-4251::DEBUG::2015-11-09 11:17:52,147::resourc= eManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll= requests {} resources {} Thread-4251::DEBUG::2015-11-09 11:17:52,148:= :resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.can= celAll requests {} Thread-4251::DEBUG::2015-11-09 11:17:52,148::task::= 993::Storage.TaskManager.Task::(_decref) Task=3D`8535d95e-dce6-4474-bd8d-78= 24f68cf68a`::ref 0 aborting False Thread-4251::INFO::2015-11-09 11:17:= 52,149::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler f= or 127.0.0.1:57854 stopped Reactor thread::INFO::2015-11-09 11:17:52,1= 50::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Ac= cepting connection from 127.0.0.1:57855 Reactor thread::DEBUG::2015-11= -09 11:17:52,158::protocoldetector::82::ProtocolDetector.Detector::(__init_= _) Using required_size=3D11 Reactor thread::INFO::2015-11-09 11:17:52,= 158::protocoldetector::118::ProtocolDetector.Detector::(handle_read) Detect= ed protocol xml from 127.0.0.1:57855 BindingXMLRPC::INFO::2015-11-09 1= 1:17:52,159::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting reques= t handler for 127.0.0.1:57855 Reactor thread::DEBUG::2015-11-09 11:17:= 52,159::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over http det= ected from ('127.0.0.1', 57855) Thread-4255::INFO::2015-11-09 11:17:52= ,162::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for= 127.0.0.1:57855 started Thread-4255::DEBUG::2015-11-09 11:17:52,162::= bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] Thread-4255::DEB= UG::2015-11-09 11:17:52,163::task::595::Storage.TaskManager.Task::(_updateS= tate) Task=3D`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::moving from state init= -> state preparing Thread-4255::INFO::2015-11-09 11:17:52,163::log= Utils::48::dispatcher::(wrapper) Run and protect: getStorageDomainStats(sdU= UID=3D'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', options=3DNone) Thread-4= 255::DEBUG::2015-11-09 11:17:52,164::resourceManager::198::Storage.Resource= Manager.Request::(__init__) ResName=3D`Storage.b4c488af-9d2f-4b7b-a6f6-74a0= bac06c41`ReqID=3D`41531754-8ba9-4fc4-8788-d4d67fa33e5c`::Request was made i= n '/usr/share/vdsm/storage/hsm.py' line '2848' at 'getStorageDomainStats'<b= r />Thread-4255::DEBUG::2015-11-09 11:17:52,164::resourceManager::542::Stor= age.ResourceManager::(registerResource) Trying to register resource 'Storag= e.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared' Thread-= 4255::DEBUG::2015-11-09 11:17:52,164::resourceManager::601::Storage.Resourc= eManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0= bac06c41' is free. Now locking as 'shared' (1 active user) Thread-4255= ::DEBUG::2015-11-09 11:17:52,164::resourceManager::238::Storage.ResourceMan= ager.Request::(grant) ResName=3D`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c= 41`ReqID=3D`41531754-8ba9-4fc4-8788-d4d67fa33e5c`::Granted request Thr= ead-4255::DEBUG::2015-11-09 11:17:52,165::task::827::Storage.TaskManager.Ta= sk::(resourceAcquired) Task=3D`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::_reso= urcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared) T= hread-4255::DEBUG::2015-11-09 11:17:52,165::task::993::Storage.TaskManager= =2ETask::(_decref) Task=3D`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::ref 1 abo= rting False Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::750::St= orage.SamplingMethod::(__call__) Trying to enter sampling method (storage= =2Esdc.refreshStorage) Thread-4255::DEBUG::2015-11-09 11:17:52,165::mi= sc::753::Storage.SamplingMethod::(__call__) Got in to sampling method = Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::750::Storage.SamplingMet= hod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) Thread-4255::DEBUG::2015-11-09 11:17:52,165::misc::753::Storage.SamplingMe= thod::(__call__) Got in to sampling method 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 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) Thread-4255::DEBUG::2015-11-09 11:1= 7:52,183::misc::760::Storage.SamplingMethod::(__call__) Returning last resu= lt Thread-4255::DEBUG::2015-11-09 11:17:52,183::misc::750::Storage.Sam= plingMethod::(__call__) Trying to enter sampling method (storage.hba.rescan= ) Thread-4255::DEBUG::2015-11-09 11:17:52,184::misc::753::Storage.Samp= lingMethod::(__call__) Got in to sampling method Thread-4255::DEBUG::2= 015-11-09 11:17:52,184::hba::56::Storage.HBA::(rescan) Starting scan T= hread-4255::DEBUG::2015-11-09 11:17:52,295::hba::62::Storage.HBA::(rescan) = Scan finished Thread-4255::DEBUG::2015-11-09 11:17:52,296::misc::760::= Storage.SamplingMethod::(__call__) Returning last result 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) Thread-4255::DEBUG::= 2015-11-09 11:17:52,362::multipath::77::Storage.Misc.excCmd::(rescan) SUCCE= SS: <err> =3D ''; <rc> =3D 0 Thread-4255::DEBUG::2015-11-0= 9 11:17:52,362::utils::676::root::(execCmd) /sbin/udevadm settle --timeout= =3D5 (cwd None) Thread-4255::DEBUG::2015-11-09 11:17:52,371::utils::69= 4::root::(execCmd) SUCCESS: <err> =3D ''; <rc> =3D 0 Threa= d-4255::DEBUG::2015-11-09 11:17:52,372::lvm::498::Storage.OperationMutex::(= _invalidateAllPvs) Operation 'lvm invalidate operation' got the operation m= utex Thread-4255::DEBUG::2015-11-09 11:17:52,372::lvm::500::Storage.Op= erationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' rele= ased the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,373::= lvm::509::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invali= date operation' got the operation mutex Thread-4255::DEBUG::2015-11-09= 11:17:52,373::lvm::511::Storage.OperationMutex::(_invalidateAllVgs) Operat= ion 'lvm invalidate operation' released the operation mutex Thread-425= 5::DEBUG::2015-11-09 11:17:52,373::lvm::529::Storage.OperationMutex::(_inva= lidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex<= br />Thread-4255::DEBUG::2015-11-09 11:17:52,373::lvm::531::Storage.Operati= onMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released = the operation mutex Thread-4255::DEBUG::2015-11-09 11:17:52,374::misc:= :760::Storage.SamplingMethod::(__call__) Returning last result Thread-= 4255::DEBUG::2015-11-09 11:17:52,386::fileSD::157::Storage.StorageDomainMan= ifest::(__init__) Reading domain in path /rhev/data-center/mnt/glusterSD/ov= irt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 Thread-42= 55::DEBUG::2015-11-09 11:17:52,387::persistentDict::192::Storage.Persistent= Dict::(__init__) Created a persistent dict with FileMetadataRW backend Thread-4255::DEBUG::2015-11-09 11:17:52,395::persistentDict::234::Storage= =2EPersistentDict::(refresh) read lines (FileMetadataRW)=3D['CLASS=3DData',= 'DESCRIPTION=3Dhosted_storage', 'IOOPTIMEOUTSEC=3D10', 'LEASERETRIES=3D3',= 'LEASETIMESEC=3D60', 'LOCKPOLICY=3D', 'LOCKRENEWALINTERVALSEC=3D5', 'POOL_= UUID=3D', 'REMOTE_PATH=3Dovirt02.mafia.kru:/engine', 'ROLE=3DRegular', 'SDU= UID=3Db4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'TYPE=3DGLUSTERFS', 'VERSION= =3D3', '_SHA_CKSUM=3Dcb09606ada74ed4155ad158923dd930264780fc8'] Thread= -4255::DEBUG::2015-11-09 11:17:52,398::fileSD::647::Storage.StorageDomain::= (imageGarbageCollector) Removing remnants of deleted images [] Thread-= 4255::INFO::2015-11-09 11:17:52,399::sd::442::Storage.StorageDomain::(_regi= sterResourceNamespaces) Resource namespace b4c488af-9d2f-4b7b-a6f6-74a0bac0= 6c41_imageNS already registered Thread-4255::INFO::2015-11-09 11:17:52= ,399::sd::450::Storage.StorageDomain::(_registerResourceNamespaces) Resourc= e namespace b4c488af-9d2f-4b7b-a6f6-74a0bac06c41_volumeNS already registere= d Thread-4255::INFO::2015-11-09 11:17:52,400::logUtils::51::dispatcher= ::(wrapper) Run and protect: getStorageDomainStats, Return response: {'stat= s': {'mdasize': 0, 'mdathreshold': True, 'mdavalid': True, 'diskfree': '210= 878988288', 'disktotal': '214643507200', 'mdafree': 0}} Thread-4255::D= EBUG::2015-11-09 11:17:52,401::task::1191::Storage.TaskManager.Task::(prepa= re) Task=3D`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::finished: {'stats': {'md= asize': 0, 'mdathreshold': True, 'mdavalid': True, 'diskfree': '21087898828= 8', 'disktotal': '214643507200', 'mdafree': 0}} Thread-4255::DEBUG::20= 15-11-09 11:17:52,401::task::595::Storage.TaskManager.Task::(_updateState) = Task=3D`04d7087f-f948-4221-8c0f-3e07e7d9bed8`::moving from state preparing = -> state finished Thread-4255::DEBUG::2015-11-09 11:17:52,401::reso= urceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.release= All requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': = < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: '= True' obj: 'None'>} Thread-4255::DEBUG::2015-11-09 11:17:52,401::re= sourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancel= All requests {} Thread-4255::DEBUG::2015-11-09 11:17:52,402::resourceM= anager::616::Storage.ResourceManager::(releaseResource) Trying to release r= esource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' Thread-4255::DE= BUG::2015-11-09 11:17:52,402::resourceManager::635::Storage.ResourceManager= ::(releaseResource) Released resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0= bac06c41' (0 active users) 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 any= one is waiting for it. Thread-4255::DEBUG::2015-11-09 11:17:52,402::re= sourceManager::649::Storage.ResourceManager::(releaseResource) No one is wa= iting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', Clearing= records. Thread-4255::DEBUG::2015-11-09 11:17:52,402::task::993::Stor= age.TaskManager.Task::(_decref) Task=3D`04d7087f-f948-4221-8c0f-3e07e7d9bed= 8`::ref 0 aborting False Thread-4255::INFO::2015-11-09 11:17:52,404::x= mlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0= =2E0.1:57855 stopped Reactor thread::INFO::2015-11-09 11:17:52,405::pr= otocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Acceptin= g connection from 127.0.0.1:57856 Reactor thread::DEBUG::2015-11-09 11= :17:52,413::protocoldetector::82::ProtocolDetector.Detector::(__init__) Usi= ng required_size=3D11 Reactor thread::INFO::2015-11-09 11:17:52,414::p= rotocoldetector::118::ProtocolDetector.Detector::(handle_read) Detected pro= tocol xml from 127.0.0.1:57856 BindingXMLRPC::INFO::2015-11-09 11:17:5= 2,414::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request hand= ler for 127.0.0.1:57856 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) Thread-4259::INFO::2015-11-09 11:17:52,417::= xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127= =2E0.0.1:57856 started Thread-4259::DEBUG::2015-11-09 11:17:52,418::bi= ndingxmlrpc::325::vds::(wrapper) client [127.0.0.1] Thread-4259::DEBUG= ::2015-11-09 11:17:52,418::task::595::Storage.TaskManager.Task::(_updateSta= te) Task=3D`9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::moving from state init -= > state preparing Thread-4259::INFO::2015-11-09 11:17:52,419::logUt= ils::48::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID=3D'b4c4= 88af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID=3D'00000000-0000-0000-0000-000000= 000000', imgUUID=3D'56461302-0710-4df0-964d-5e7b1ff07828', leafUUID=3D'8f8e= e034-de86-4438-b6eb-9109faa8b3d3') Thread-4259::DEBUG::2015-11-09 11:1= 7:52,419::resourceManager::198::Storage.ResourceManager.Request::(__init__)= ResName=3D`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=3D`bec7c8c3-= 42b9-4acb-88cf-841d9dc28fb0`::Request was made in '/usr/share/vdsm/storage/= hsm.py' line '3205' at 'prepareImage' Thread-4259::DEBUG::2015-11-09 1= 1:17:52,419::resourceManager::542::Storage.ResourceManager::(registerResour= ce) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c= 41' for lock type 'shared' Thread-4259::DEBUG::2015-11-09 11:17:52,420= ::resourceManager::601::Storage.ResourceManager::(registerResource) Resourc= e 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 's= hared' (1 active user) Thread-4259::DEBUG::2015-11-09 11:17:52,420::re= sourceManager::238::Storage.ResourceManager.Request::(grant) ResName=3D`Sto= rage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=3D`bec7c8c3-42b9-4acb-88cf-= 841d9dc28fb0`::Granted request Thread-4259::DEBUG::2015-11-09 11:17:52= ,420::task::827::Storage.TaskManager.Task::(resourceAcquired) Task=3D`9dbe0= 1b2-e3e0-466b-90e1-b9803dfce88b`::_resourcesAcquired: Storage.b4c488af-9d2f= -4b7b-a6f6-74a0bac06c41 (shared) Thread-4259::DEBUG::2015-11-09 11:17:= 52,420::task::993::Storage.TaskManager.Task::(_decref) Task=3D`9dbe01b2-e3e= 0-466b-90e1-b9803dfce88b`::ref 1 aborting False Thread-4259::DEBUG::20= 15-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 Thread-4259::DEBUG::= 2015-11-09 11:17:52,446::fileUtils::143::Storage.fileUtils::(createdir) Cre= ating directory: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41= mode: None 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 Thread-4259::DEBUG::2015-11-09 = 11:17:52,446::fileSD::511::Storage.StorageDomain::(createImageLinks) Creati= ng symlink from /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b= 4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff0= 7828 to /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/56461302= -0710-4df0-964d-5e7b1ff07828 Thread-4259::DEBUG::2015-11-09 11:17:52,4= 47::fileSD::516::Storage.StorageDomain::(createImageLinks) img run dir alre= ady exists: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/5646= 1302-0710-4df0-964d-5e7b1ff07828 Thread-4259::DEBUG::2015-11-09 11:17:= 52,448::fileVolume::535::Storage.Volume::(validateVolumePath) validate path= for 8f8ee034-de86-4438-b6eb-9109faa8b3d3 Thread-4259::INFO::2015-11-0= 9 11:17:52,450::logUtils::51::dispatcher::(wrapper) Run and protect: prepar= eImage, Return response: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a= 0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-cente= r/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06= c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-910= 9faa8b3d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath= ': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2= f-4b7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee0= 34-de86-4438-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-= 5e7b1ff07828'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a= 0bac06c41/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109= faa8b3d3', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac= 06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mn= t/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/= images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa= 8b3d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u= '/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b= 7b-a6f6-74a0bac06c41/images/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-d= e86-4438-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-5e7b= 1ff07828'}]} Thread-4259::DEBUG::2015-11-09 11:17:52,450::task::1191::= Storage.TaskManager.Task::(prepare) Task=3D`9dbe01b2-e3e0-466b-90e1-b9803df= ce88b`::finished: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c= 41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/g= lusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/ima= ges/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3= d3', 'volumeID': u'8f8ee034-de86-4438-b6eb-9109faa8b3d3', 'leasePath': u'/r= hev/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-5e7b1ff= 07828'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c= 41/56461302-0710-4df0-964d-5e7b1ff07828/8f8ee034-de86-4438-b6eb-9109faa8b3d= 3', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41',= 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glust= erSD/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-443= 8-b6eb-9109faa8b3d3.lease', 'imageID': '56461302-0710-4df0-964d-5e7b1ff0782= 8'}]} Thread-4259::DEBUG::2015-11-09 11:17:52,450::task::595::Storage= =2ETaskManager.Task::(_updateState) Task=3D`9dbe01b2-e3e0-466b-90e1-b9803df= ce88b`::moving from state preparing -> state finished Thread-4259::= DEBUG::2015-11-09 11:17:52,450::resourceManager::940::Storage.ResourceManag= er.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b4c= 488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f= -4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>} Thread-4259= ::DEBUG::2015-11-09 11:17:52,450::resourceManager::977::Storage.ResourceMan= ager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-4259::DEBUG= ::2015-11-09 11:17:52,451::resourceManager::616::Storage.ResourceManager::(= releaseResource) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f= 6-74a0bac06c41' Thread-4259::DEBUG::2015-11-09 11:17:52,451::resourceM= anager::635::Storage.ResourceManager::(releaseResource) Released resource '= Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users) Thread-= 4259::DEBUG::2015-11-09 11:17:52,451::resourceManager::641::Storage.Resourc= eManager::(releaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0b= ac06c41' is free, finding out if anyone is waiting for it. Thread-4259= ::DEBUG::2015-11-09 11:17:52,451::resourceManager::649::Storage.ResourceMan= ager::(releaseResource) No one is waiting for resource 'Storage.b4c488af-9d= 2f-4b7b-a6f6-74a0bac06c41', Clearing records. Thread-4259::DEBUG::2015= -11-09 11:17:52,451::task::993::Storage.TaskManager.Task::(_decref) Task=3D= `9dbe01b2-e3e0-466b-90e1-b9803dfce88b`::ref 0 aborting False Thread-42= 59::INFO::2015-11-09 11:17:52,454::xmlrpc::92::vds.XMLRPCServer::(_process_= requests) Request handler for 127.0.0.1:57856 stopped Reactor thread::= INFO::2015-11-09 11:17:52,454::protocoldetector::72::ProtocolDetector.Accep= torImpl::(handle_accept) Accepting connection from 127.0.0.1:57857 Rea= ctor thread::DEBUG::2015-11-09 11:17:52,463::protocoldetector::82::Protocol= Detector.Detector::(__init__) Using required_size=3D11 Reactor thread:= :INFO::2015-11-09 11:17:52,463::protocoldetector::118::ProtocolDetector.Det= ector::(handle_read) Detected protocol xml from 127.0.0.1:57857 Reacto= r thread::DEBUG::2015-11-09 11:17:52,464::bindingxmlrpc::1297::XmlDetector:= :(handle_socket) xml over http detected from ('127.0.0.1', 57857) Bind= ingXMLRPC::INFO::2015-11-09 11:17:52,464::xmlrpc::73::vds.XMLRPCServer::(ha= ndle_request) Starting request handler for 127.0.0.1:57857 Thread-4260= ::INFO::2015-11-09 11:17:52,466::xmlrpc::84::vds.XMLRPCServer::(_process_re= quests) Request handler for 127.0.0.1:57857 started Thread-4260::DEBUG= ::2015-11-09 11:17:52,467::bindingxmlrpc::325::vds::(wrapper) client [127= =2E0.0.1] Thread-4260::DEBUG::2015-11-09 11:17:52,467::task::595::Stor= age.TaskManager.Task::(_updateState) Task=3D`aed16a50-ede9-4ff5-92ef-356692= fd56ae`::moving from state init -> state preparing Thread-4260::INF= O::2015-11-09 11:17:52,467::logUtils::48::dispatcher::(wrapper) Run and pro= tect: prepareImage(sdUUID=3D'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID= =3D'00000000-0000-0000-0000-000000000000', imgUUID=3D'fd81353f-b654-4493-bc= af-2f417849b830', leafUUID=3D'8bb29fcb-c109-4f0a-a227-3819b6ecfdd9') T= hread-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::198::Storage= =2EResourceManager.Request::(__init__) ResName=3D`Storage.b4c488af-9d2f-4b7= b-a6f6-74a0bac06c41`ReqID=3D`974119cd-1351-46e9-8062-ffb1298c4ac9`::Request= was made in '/usr/share/vdsm/storage/hsm.py' line '3205' at 'prepareImage'= Thread-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::542::St= orage.ResourceManager::(registerResource) Trying to register resource 'Stor= age.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock type 'shared' Threa= d-4260::DEBUG::2015-11-09 11:17:52,468::resourceManager::601::Storage.Resou= rceManager::(registerResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74= a0bac06c41' is free. Now locking as 'shared' (1 active user) Thread-42= 60::DEBUG::2015-11-09 11:17:52,468::resourceManager::238::Storage.ResourceM= anager.Request::(grant) ResName=3D`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac0= 6c41`ReqID=3D`974119cd-1351-46e9-8062-ffb1298c4ac9`::Granted request T= hread-4260::DEBUG::2015-11-09 11:17:52,469::task::827::Storage.TaskManager= =2ETask::(resourceAcquired) Task=3D`aed16a50-ede9-4ff5-92ef-356692fd56ae`::= _resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared)<b= r />Thread-4260::DEBUG::2015-11-09 11:17:52,469::task::993::Storage.TaskMan= ager.Task::(_decref) Task=3D`aed16a50-ede9-4ff5-92ef-356692fd56ae`::ref 1 a= borting False 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-74a= 0bac06c41/images/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a2= 27-3819b6ecfdd9 Thread-4260::DEBUG::2015-11-09 11:17:52,486::fileUtils= ::143::Storage.fileUtils::(createdir) Creating directory: /var/run/vdsm/sto= rage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 mode: None Thread-4260::WARN= ING::2015-11-09 11:17:52,487::fileUtils::152::Storage.fileUtils::(createdir= ) Dir /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 already ex= ists Thread-4260::DEBUG::2015-11-09 11:17:52,487::fileSD::511::Storage= =2EStorageDomain::(createImageLinks) Creating symlink from /rhev/data-cente= r/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06= c41/images/fd81353f-b654-4493-bcaf-2f417849b830 to /var/run/vdsm/storage/b4= c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-4493-bcaf-2f417849b830 Thread-4260::DEBUG::2015-11-09 11:17:52,487::fileSD::516::Storage.Storage= Domain::(createImageLinks) img run dir already exists: /var/run/vdsm/storag= e/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-4493-bcaf-2f417849b830= Thread-4260::DEBUG::2015-11-09 11:17:52,488::fileVolume::535::Storage= =2EVolume::(validateVolumePath) validate path for 8bb29fcb-c109-4f0a-a227-3= 819b6ecfdd9 Thread-4260::INFO::2015-11-09 11:17:52,490::logUtils::51::= dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'inf= o': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path',= 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia= =2Ekru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-44= 93-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8= bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/= glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/im= ages/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecf= dd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}, 'path': u'/= var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-449= 3-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= =2Ekru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-44= 93-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8= bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/= glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/im= ages/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecf= dd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}]} Threa= d-4260::DEBUG::2015-11-09 11:17:52,490::task::1191::Storage.TaskManager.Tas= k::(prepare) Task=3D`aed16a50-ede9-4ff5-92ef-356692fd56ae`::finished: {'inf= o': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path',= 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia= =2Ekru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-44= 93-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8= bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/= glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/im= ages/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecf= dd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}, 'path': u'/= var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/fd81353f-b654-449= 3-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= =2Ekru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/fd81353f-b654-44= 93-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'volumeID': u'8= bb29fcb-c109-4f0a-a227-3819b6ecfdd9', 'leasePath': u'/rhev/data-center/mnt/= glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/im= ages/fd81353f-b654-4493-bcaf-2f417849b830/8bb29fcb-c109-4f0a-a227-3819b6ecf= dd9.lease', 'imageID': 'fd81353f-b654-4493-bcaf-2f417849b830'}]} Threa= d-4260::DEBUG::2015-11-09 11:17:52,490::task::595::Storage.TaskManager.Task= ::(_updateState) Task=3D`aed16a50-ede9-4ff5-92ef-356692fd56ae`::moving from= state preparing -> state finished Thread-4260::DEBUG::2015-11-09 1= 1:17:52,490::resourceManager::940::Storage.ResourceManager.Owner::(releaseA= ll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b7b-a6f= 6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac0= 6c41', isValid: 'True' obj: 'None'>} Thread-4260::DEBUG::2015-11-09= 11:17:52,491::resourceManager::977::Storage.ResourceManager.Owner::(cancel= All) Owner.cancelAll requests {} Thread-4260::DEBUG::2015-11-09 11:17:= 52,491::resourceManager::616::Storage.ResourceManager::(releaseResource) Tr= ying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' Thread-4260::DEBUG::2015-11-09 11:17:52,491::resourceManager::635::Storag= e.ResourceManager::(releaseResource) Released resource 'Storage.b4c488af-9d= 2f-4b7b-a6f6-74a0bac06c41' (0 active users) Thread-4260::DEBUG::2015-1= 1-09 11:17:52,491::resourceManager::641::Storage.ResourceManager::(releaseR= esource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free, f= inding out if anyone is waiting for it. Thread-4260::DEBUG::2015-11-09= 11:17:52,491::resourceManager::649::Storage.ResourceManager::(releaseResou= rce) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0ba= c06c41', Clearing records. Thread-4260::DEBUG::2015-11-09 11:17:52,492= ::task::993::Storage.TaskManager.Task::(_decref) Task=3D`aed16a50-ede9-4ff5= -92ef-356692fd56ae`::ref 0 aborting False Thread-4260::INFO::2015-11-0= 9 11:17:52,494::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request h= andler for 127.0.0.1:57857 stopped Reactor thread::INFO::2015-11-09 11= :17:52,494::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_ac= cept) Accepting connection from 127.0.0.1:57858 Reactor thread::DEBUG:= :2015-11-09 11:17:52,503::protocoldetector::82::ProtocolDetector.Detector::= (__init__) Using required_size=3D11 Reactor thread::INFO::2015-11-09 1= 1:17:52,504::protocoldetector::118::ProtocolDetector.Detector::(handle_read= ) Detected protocol xml from 127.0.0.1:57858 BindingXMLRPC::INFO::2015= -11-09 11:17:52,504::xmlrpc::73::vds.XMLRPCServer::(handle_request) Startin= g request handler for 127.0.0.1:57858 Reactor thread::DEBUG::2015-11-0= 9 11:17:52,504::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml over = http detected from ('127.0.0.1', 57858) Thread-4261::INFO::2015-11-09 = 11:17:52,507::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request han= dler for 127.0.0.1:57858 started Thread-4261::DEBUG::2015-11-09 11:17:= 52,508::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] Thread-4= 261::DEBUG::2015-11-09 11:17:52,508::task::595::Storage.TaskManager.Task::(= _updateState) Task=3D`d39463fd-486f-4280-903a-51b72862b648`::moving from st= ate init -> state preparing Thread-4261::INFO::2015-11-09 11:17:52,= 509::logUtils::48::dispatcher::(wrapper) Run and protect: prepareImage(sdUU= ID=3D'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', spUUID=3D'00000000-0000-0000-0= 000-000000000000', imgUUID=3D'0e1c20d1-94aa-4003-8e12-0dbbf06a6af8', leafUU= ID=3D'3fc3362d-ab6d-4e06-bd72-82d5750c7095') Thread-4261::DEBUG::2015-= 11-09 11:17:52,509::resourceManager::198::Storage.ResourceManager.Request::= (__init__) ResName=3D`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=3D= `240c2aba-6c2e-44da-890d-c3d605e1933f`::Request was made in '/usr/share/vds= m/storage/hsm.py' line '3205' at 'prepareImage' Thread-4261::DEBUG::20= 15-11-09 11:17:52,509::resourceManager::542::Storage.ResourceManager::(regi= sterResource) Trying to register resource 'Storage.b4c488af-9d2f-4b7b-a6f6-= 74a0bac06c41' for lock type 'shared' Thread-4261::DEBUG::2015-11-09 11= :17:52,509::resourceManager::601::Storage.ResourceManager::(registerResourc= e) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now loc= king as 'shared' (1 active user) Thread-4261::DEBUG::2015-11-09 11:17:= 52,510::resourceManager::238::Storage.ResourceManager.Request::(grant) ResN= ame=3D`Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=3D`240c2aba-6c2e-= 44da-890d-c3d605e1933f`::Granted request Thread-4261::DEBUG::2015-11-0= 9 11:17:52,510::task::827::Storage.TaskManager.Task::(resourceAcquired) Tas= k=3D`d39463fd-486f-4280-903a-51b72862b648`::_resourcesAcquired: Storage.b4c= 488af-9d2f-4b7b-a6f6-74a0bac06c41 (shared) Thread-4261::DEBUG::2015-11= -09 11:17:52,510::task::993::Storage.TaskManager.Task::(_decref) Task=3D`d3= 9463fd-486f-4280-903a-51b72862b648`::ref 1 aborting False Thread-4261:= :DEBUG::2015-11-09 11:17:52,526::fileSD::536::Storage.StorageDomain::(activ= ateVolumes) Fixing permissions on /rhev/data-center/mnt/glusterSD/ovirt02= =2Emafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-9= 4aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095 Thread= -4261::DEBUG::2015-11-09 11:17:52,528::fileUtils::143::Storage.fileUtils::(= createdir) Creating directory: /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f= 6-74a0bac06c41 mode: None Thread-4261::WARNING::2015-11-09 11:17:52,52= 8::fileUtils::152::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage= /b4c488af-9d2f-4b7b-a6f6-74a0bac06c41 already exists Thread-4261::DEBU= G::2015-11-09 11:17:52,528::fileSD::511::Storage.StorageDomain::(createImag= eLinks) Creating symlink from /rhev/data-center/mnt/glusterSD/ovirt02.mafia= =2Ekru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-40= 03-8e12-0dbbf06a6af8 to /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0b= ac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8 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-7= 4a0bac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8 Thread-4261::DEBUG::2= 015-11-09 11:17:52,530::fileVolume::535::Storage.Volume::(validateVolumePat= h) validate path for 3fc3362d-ab6d-4e06-bd72-82d5750c7095 Thread-4261:= :INFO::2015-11-09 11:17:52,531::logUtils::51::dispatcher::(wrapper) Run and= protect: prepareImage, Return response: {'info': {'domainID': 'b4c488af-9d= 2f-4b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'= /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7= b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab= 6d-4e06-bd72-82d5750c7095', 'volumeID': u'3fc3362d-ab6d-4e06-bd72-82d5750c7= 095', 'leasePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_eng= ine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0db= bf06a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1= -94aa-4003-8e12-0dbbf06a6af8'}, 'path': u'/var/run/vdsm/storage/b4c488af-9d= 2f-4b7b-a6f6-74a0bac06c41/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6= d-4e06-bd72-82d5750c7095', 'imgVolumesInfo': [{'domainID': 'b4c488af-9d2f-4= b7b-a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhe= v/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6= f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4= e06-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-0dbbf06= a6af8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94a= a-4003-8e12-0dbbf06a6af8'}]} Thread-4261::DEBUG::2015-11-09 11:17:52,5= 31::task::1191::Storage.TaskManager.Task::(prepare) Task=3D`d39463fd-486f-4= 280-903a-51b72862b648`::finished: {'info': {'domainID': 'b4c488af-9d2f-4b7b= -a6f6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/d= ata-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/b4c= 488af-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6a= f8/3fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94aa-4= 003-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-a6f= 6-74a0bac06c41', 'volType': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-= center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0= bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3fc3362d-ab6d-4e06-bd7= 2-82d5750c7095', 'volumeID': u'3fc3362d-ab6d-4e06-bd72-82d5750c7095', 'leas= ePath': u'/rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488a= f-9d2f-4b7b-a6f6-74a0bac06c41/images/0e1c20d1-94aa-4003-8e12-0dbbf06a6af8/3= fc3362d-ab6d-4e06-bd72-82d5750c7095.lease', 'imageID': '0e1c20d1-94aa-4003-= 8e12-0dbbf06a6af8'}]} Thread-4261::DEBUG::2015-11-09 11:17:52,532::tas= k::595::Storage.TaskManager.Task::(_updateState) Task=3D`d39463fd-486f-4280= -903a-51b72862b648`::moving from state preparing -> state finished = Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::940::Storage= =2EResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resourc= es {'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': < ResourceRef 'Stora= ge.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', isValid: 'True' obj: 'None'>}<= br />Thread-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::977::Sto= rage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Th= read-4261::DEBUG::2015-11-09 11:17:52,532::resourceManager::616::Storage.Re= sourceManager::(releaseResource) Trying to release resource 'Storage.b4c488= af-9d2f-4b7b-a6f6-74a0bac06c41' Thread-4261::DEBUG::2015-11-09 11:17:5= 2,532::resourceManager::635::Storage.ResourceManager::(releaseResource) Rel= eased resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active use= rs) 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= =2E 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. Thre= ad-4261::DEBUG::2015-11-09 11:17:52,533::task::993::Storage.TaskManager.Tas= k::(_decref) Task=3D`d39463fd-486f-4280-903a-51b72862b648`::ref 0 aborting = False Thread-4261::INFO::2015-11-09 11:17:52,535::xmlrpc::92::vds.XMLR= PCServer::(_process_requests) Request handler for 127.0.0.1:57858 stopped<b= r />Reactor thread::INFO::2015-11-09 11:17:52,536::protocoldetector::72::Pr= otocolDetector.AcceptorImpl::(handle_accept) Accepting connection from 127= =2E0.0.1:57859 Reactor thread::DEBUG::2015-11-09 11:17:52,544::protoco= ldetector::82::ProtocolDetector.Detector::(__init__) Using required_size=3D= 11 Reactor thread::INFO::2015-11-09 11:17:52,545::protocoldetector::11= 8::ProtocolDetector.Detector::(handle_read) Detected protocol xml from 127= =2E0.0.1:57859 Reactor thread::DEBUG::2015-11-09 11:17:52,545::binding= xmlrpc::1297::XmlDetector::(handle_socket) xml over http detected from ('12= 7.0.0.1', 57859) BindingXMLRPC::INFO::2015-11-09 11:17:52,545::xmlrpc:= :73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0= =2E0.1:57859 Thread-4262::INFO::2015-11-09 11:17:52,548::xmlrpc::84::v= ds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:57859 st= arted Thread-4262::DEBUG::2015-11-09 11:17:52,548::bindingxmlrpc::325:= :vds::(wrapper) client [127.0.0.1] Thread-4262::DEBUG::2015-11-09 11:1= 7:52,549::task::595::Storage.TaskManager.Task::(_updateState) Task=3D`0eebd= b1c-6c4d-4b86-a2fa-00ad35a19f24`::moving from state init -> state prepar= ing Thread-4262::INFO::2015-11-09 11:17:52,549::logUtils::48::dispatch= er::(wrapper) Run and protect: prepareImage(sdUUID=3D'b4c488af-9d2f-4b7b-a6= f6-74a0bac06c41', spUUID=3D'00000000-0000-0000-0000-000000000000', imgUUID= =3D'350fb787-049a-4174-8914-f371aabfa72c', leafUUID=3D'02c5d59d-638c-4672-8= 14d-d734e334e24a') Thread-4262::DEBUG::2015-11-09 11:17:52,549::resour= ceManager::198::Storage.ResourceManager.Request::(__init__) ResName=3D`Stor= age.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41`ReqID=3D`fd9ea6d0-3a31-4ec6-a74c-8= b84b2e51746`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '32= 05' at 'prepareImage' Thread-4262::DEBUG::2015-11-09 11:17:52,550::res= ourceManager::542::Storage.ResourceManager::(registerResource) Trying to re= gister resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' for lock typ= e 'shared' Thread-4262::DEBUG::2015-11-09 11:17:52,550::resourceManage= r::601::Storage.ResourceManager::(registerResource) Resource 'Storage.b4c48= 8af-9d2f-4b7b-a6f6-74a0bac06c41' is free. Now locking as 'shared' (1 active= user) Thread-4262::DEBUG::2015-11-09 11:17:52,550::resourceManager::2= 38::Storage.ResourceManager.Request::(grant) ResName=3D`Storage.b4c488af-9d= 2f-4b7b-a6f6-74a0bac06c41`ReqID=3D`fd9ea6d0-3a31-4ec6-a74c-8b84b2e51746`::G= ranted request Thread-4262::DEBUG::2015-11-09 11:17:52,550::task::827:= :Storage.TaskManager.Task::(resourceAcquired) Task=3D`0eebdb1c-6c4d-4b86-a2= fa-00ad35a19f24`::_resourcesAcquired: Storage.b4c488af-9d2f-4b7b-a6f6-74a0b= ac06c41 (shared) Thread-4262::DEBUG::2015-11-09 11:17:52,551::task::99= 3::Storage.TaskManager.Task::(_decref) Task=3D`0eebdb1c-6c4d-4b86-a2fa-00ad= 35a19f24`::ref 1 aborting False Thread-4262::DEBUG::2015-11-09 11:17:5= 2,566::fileSD::536::Storage.StorageDomain::(activateVolumes) Fixing permiss= ions on /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-= 9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c= 5d59d-638c-4672-814d-d734e334e24a 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 Thread-4262::WARNING::2015-11-09 11:17:52,568::fileUtils::152::Storage.fil= eUtils::(createdir) Dir /var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0b= ac06c41 already exists Thread-4262::DEBUG::2015-11-09 11:17:52,568::fi= leSD::511::Storage.StorageDomain::(createImageLinks) Creating symlink from = /rhev/data-center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7= b-a6f6-74a0bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c to /var/run= /vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb787-049a-4174-8914-= f371aabfa72c 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-8= 914-f371aabfa72c Thread-4262::DEBUG::2015-11-09 11:17:52,570::fileVolu= me::535::Storage.Volume::(validateVolumePath) validate path for 02c5d59d-63= 8c-4672-814d-d734e334e24a Thread-4262::INFO::2015-11-09 11:17:52,572::= logUtils::51::dispatcher::(wrapper) Run and protect: prepareImage, Return r= esponse: {'info': {'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'vol= Type': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/= ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb= 787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'vol= umeID': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-= center/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0= bac06c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814= d-d734e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}, = 'path': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb7= 87-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'imgV= olumesInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType= ': 'path', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovir= t02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-= 049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeI= D': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-cent= er/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac0= 6c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d7= 34e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}]} Thread-4262::DEBUG::2015-11-09 11:17:52,573::task::1191::Storage.TaskMana= ger.Task::(prepare) Task=3D`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= =2Emafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-0= 49a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeID= ': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-cente= r/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06= c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d73= 4e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}, 'path= ': u'/var/run/vdsm/storage/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/350fb787-04= 9a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'imgVolume= sInfo': [{'domainID': 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41', 'volType': 'p= ath', 'leaseOffset': 0, 'path': u'/rhev/data-center/mnt/glusterSD/ovirt02= =2Emafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06c41/images/350fb787-0= 49a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d734e334e24a', 'volumeID= ': u'02c5d59d-638c-4672-814d-d734e334e24a', 'leasePath': u'/rhev/data-cente= r/mnt/glusterSD/ovirt02.mafia.kru:_engine/b4c488af-9d2f-4b7b-a6f6-74a0bac06= c41/images/350fb787-049a-4174-8914-f371aabfa72c/02c5d59d-638c-4672-814d-d73= 4e334e24a.lease', 'imageID': '350fb787-049a-4174-8914-f371aabfa72c'}]} Thread-4262::DEBUG::2015-11-09 11:17:52,573::task::595::Storage.TaskManage= r.Task::(_updateState) Task=3D`0eebdb1c-6c4d-4b86-a2fa-00ad35a19f24`::movin= g from state preparing -> state finished Thread-4262::DEBUG::2015-1= 1-09 11:17:52,573::resourceManager::940::Storage.ResourceManager.Owner::(re= leaseAll) Owner.releaseAll requests {} resources {'Storage.b4c488af-9d2f-4b= 7b-a6f6-74a0bac06c41': < ResourceRef 'Storage.b4c488af-9d2f-4b7b-a6f6-74= a0bac06c41', isValid: 'True' obj: 'None'>} Thread-4262::DEBUG::2015= -11-09 11:17:52,573::resourceManager::977::Storage.ResourceManager.Owner::(= cancelAll) Owner.cancelAll requests {} Thread-4262::DEBUG::2015-11-09 = 11:17:52,573::resourceManager::616::Storage.ResourceManager::(releaseResour= ce) Trying to release resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c4= 1' Thread-4262::DEBUG::2015-11-09 11:17:52,573::resourceManager::635::= Storage.ResourceManager::(releaseResource) Released resource 'Storage.b4c48= 8af-9d2f-4b7b-a6f6-74a0bac06c41' (0 active users) Thread-4262::DEBUG::= 2015-11-09 11:17:52,574::resourceManager::641::Storage.ResourceManager::(re= leaseResource) Resource 'Storage.b4c488af-9d2f-4b7b-a6f6-74a0bac06c41' is f= ree, finding out if anyone is waiting for it. Thread-4262::DEBUG::2015= -11-09 11:17:52,574::resourceManager::649::Storage.ResourceManager::(releas= eResource) No one is waiting for resource 'Storage.b4c488af-9d2f-4b7b-a6f6-= 74a0bac06c41', Clearing records. Thread-4262::DEBUG::2015-11-09 11:17:= 52,574::task::993::Storage.TaskManager.Task::(_decref) Task=3D`0eebdb1c-6c4= d-4b86-a2fa-00ad35a19f24`::ref 0 aborting False Thread-4262::INFO::201= 5-11-09 11:17:52,576::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Req= uest handler for 127.0.0.1:57859 stopped Reactor thread::INFO::2015-11= -09 11:17:52,610::protocoldetector::72::ProtocolDetector.AcceptorImpl::(han= dle_accept) Accepting connection from 127.0.0.1:57860 Reactor thread::= DEBUG::2015-11-09 11:17:52,619::protocoldetector::82::ProtocolDetector.Dete= ctor::(__init__) Using required_size=3D11 Reactor thread::INFO::2015-1= 1-09 11:17:52,619::protocoldetector::118::ProtocolDetector.Detector::(handl= e_read) Detected protocol xml from 127.0.0.1:57860 BindingXMLRPC::INFO= ::2015-11-09 11:17:52,620::xmlrpc::73::vds.XMLRPCServer::(handle_request) S= tarting request handler for 127.0.0.1:57860 Reactor thread::DEBUG::201= 5-11-09 11:17:52,620::bindingxmlrpc::1297::XmlDetector::(handle_socket) xml= over http detected from ('127.0.0.1', 57860) Thread-4263::INFO::2015-= 11-09 11:17:52,623::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Reque= st handler for 127.0.0.1:57860 started Thread-4263::DEBUG::2015-11-09 = 11:17:52,623::bindingxmlrpc::325::vds::(wrapper) client [127.0.0.1] Th= read-4263::DEBUG::2015-11-09 11:17:52,624::task::595::Storage.TaskManager= =2ETask::(_updateState) Task=3D`6fd1d011-d931-4eca-b93b-c0fc3a1b4107`::movi= ng from state init -> state preparing Thread-4263::INFO::2015-11-09= 11:17:52,624::logUtils::48::dispatcher::(wrapper) Run and protect: repoSta= ts(options=3DNone) Thread-4263::INFO::2015-11-09 11:17:52,624::logUtil= s::51::dispatcher::(wrapper) Run and protect: repoStats, Return response: {= 'b4c488af-9d2f-4b7b-a6f6-74a0bac06c41': {'code': 0, 'actual': True, 'versio= n': 3, 'acquired': True, 'delay': '0.000392118', 'lastCheck': '6.0', 'valid= ': True}, u'0af99439-f140-4636-90f7-f43904735da0': {'code': 0, 'actual': Tr= ue, 'version': 3, 'acquired': True, 'delay': '0.000382969', 'lastCheck': '4= =2E5', 'valid': True}} Thread-4263::DEBUG::2015-11-09 11:17:52,624::ta= sk::1191::Storage.TaskManager.Task::(prepare) Task=3D`6fd1d011-d931-4eca-b9= 3b-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-f43904735d= a0': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '= 0.000382969', 'lastCheck': '4.5', 'valid': True}} Thread-4263::DEBUG::= 2015-11-09 11:17:52,625::task::595::Storage.TaskManager.Task::(_updateState= ) Task=3D`6fd1d011-d931-4eca-b93b-c0fc3a1b4107`::moving from state preparin= g -> state finished Thread-4263::DEBUG::2015-11-09 11:17:52,625::re= sourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.relea= seAll requests {} resources {} Thread-4263::DEBUG::2015-11-09 11:17:52= ,625::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owne= r.cancelAll requests {} Thread-4263::DEBUG::2015-11-09 11:17:52,625::t= ask::993::Storage.TaskManager.Task::(_decref) Task=3D`6fd1d011-d931-4eca-b9= 3b-c0fc3a1b4107`::ref 0 aborting False Thread-4263::INFO::2015-11-09 1= 1:17:52,627::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request hand= ler for 127.0.0.1:57860 stopped mailbox.SPMMonitor::DEBUG::2015-11-09 = 11:17:52,829::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) dd= if=3D/rhev/data-center/00000001-0001-0001-0001-000000000230/mastersd/dom_m= d/inbox iflag=3Ddirect,fullblock count=3D1 bs=3D1024000 (cwd None) mai= lbox.SPMMonitor::DEBUG::2015-11-09 11:17:52,845::storage_mailbox::735::Stor= age.Misc.excCmd::(_checkForMail) SUCCESS: <err> =3D '1+0 records in\n= 1+0 records out\n1024000 bytes (1.0 MB) copied, 0.00494757 s, 207 MB/s\n'; = <rc> =3D 0 <div>-- Florent BELLO Service Informatique informatique@ville-kourou= =2Efr 0594 22 31 22 Mairie de Kourou </div> </body></html> --=_920b73690f5d77fd5fed2f8d20a489a7--

2 3

ovirt-hosted-engine-setup and single machine install
by Johan Vermeulen 24 Nov '15

24 Nov '15

Hello All, after configuring a first setup, based on the quick start guide, I'm now looking at the hosted-engine setup. My question is: after I do the hosted-engine-setup, how do I setup vm's on the same machine that hosts the now-virtualized engine? Greetings, J.

4 4

Invitation: [Deep dive] Host Network QoS - oVirt 3.6 @ Tue Nov 24 5pm - Thu Nov 26, 2015 6pm (ibarkan@redhat.com)
by ibarkan＠redhat.com 24 Nov '15

24 Nov '15

You have been invited to the following event. Title: [Deep dive] Host Network QoS - oVirt 3.6 Hangouts on air: https://plus.google.com/events/c3la9vdse911atq991qflogtq0g you tube link: https://plus.google.com/events/c3la9vdse911atq991qflogtq0g When: Tue Nov 24 5pm - Thu Nov 26, 2015 6pm Jerusalem Calendar: ibarkan(a)redhat.com Who: * ibarkan(a)redhat.com - organizer * users(a)ovirt.org Event details: https://www.google.com/calendar/event?action=VIEW&eid=NGZxZXU0dDRka2ZrMmd1c… Invitation from Google Calendar: https://www.google.com/calendar/ You are receiving this courtesy email at the account users(a)ovirt.org because you are an attendee of this event. To stop receiving future updates for this event, decline this event. Alternatively you can sign up for a Google account at https://www.google.com/calendar/ and control your notification settings for your entire calendar. Forwarding this invitation could allow any recipient to modify your RSVP response. Learn more at https://support.google.com/calendar/answer/37135#forwarding

1 0

[ANN] oVirt 3.5.6 Third Release Candidate is now available for testing
by Sandro Bonazzola 24 Nov '15

24 Nov '15

The oVirt Project is pleased to announce the availability of the Third oVirt 3.5.6 Release Candidate for testing, as of November 24th, 2015. This release is available now for Red Hat Enterprise Linux 6.7, CentOS Linux 6.7 (or similar) and Red Hat Enterprise Linux 7.1, CentOS Linux 7.1 (or similar). This release supports Hypervisor Hosts running Red Hat Enterprise Linux 6.7, CentOS Linux 6.7 (or similar) and Red Hat Enterprise Linux 7.1, CentOS Linux 7.1 (or similar). This release includes updated packages for: - VDSM See the release notes [1] for a list of fixed bugs. Please refer to release notes [1] for Installation / Upgrade instructions. a new oVirt Live ISO is already available[2]. Please note that mirrors[3] may need usually one day before being synchronized. Please refer to the release notes for known issues in this release. Please add yourself to the test page[4] if you're testing this release. [1] http://www.ovirt.org/OVirt_3.5.6_Release_Notes [2] http://resources.ovirt.org/pub/ovirt-3.5-pre/iso/ovirt-live/ [3] http://www.ovirt.org/Repository_mirrors#Current_mirrors [4] http://www.ovirt.org/Testing/oVirt_3.5.6_Testing -- Sandro Bonazzola Better technology. Faster innovation. Powered by community collaboration. See how it works at redhat.com

1 0

Re: [ovirt-users] Ovirt 3.6 | After upgrade host can not connect to storage domains | returned by VDSM was: 480
by Punit Dambiwal 24 Nov '15

24 Nov '15

Hi Sahina, Either after make the changes in the vdsm.conf,still not able to connect to the replica=2 storage.. Thanks, Punit On Mon, Nov 23, 2015 at 4:15 PM, Punit Dambiwal <hypunit(a)gmail.com> wrote: > Hi Sahina, > > Thanks for the update...would you mind to let me know the correct syntax > to add the line in the vdsm.conf ?? > > Thanks, > Punit > > On Mon, Nov 23, 2015 at 3:48 PM, Sahina Bose <sabose(a)redhat.com> wrote: > >> You can change the allowed_replica_count to 2 in vdsm.conf - though this >> is not recommended in production. Supported replica count is 3. >> >> thanks >> sahina >> >> >> On 11/23/2015 07:58 AM, Punit Dambiwal wrote: >> >> Hi Sahina, >> >> Is there any workaround to solve this issue ? >> >> Thanks, >> Punit >> >> On Wed, Nov 11, 2015 at 9:36 AM, Sahina Bose <sabose(a)redhat.com> wrote: >> >>> Hi, >>> >>> Thanks for your email. I will be back on 16th Nov and will get back to >>> you then. >>> >>> thanks >>> sahina >>> >> >> >> >

2 1

← Newer
1
...
6
7
8
9
10
11
12
...
25
Older →

Jump to page: