[Users] Gluster VM stuck in "waiting for launch" state

Wed Oct 30 11:30:45 UTC 2013

----- Original Message -----

> From: "Alessandro Bianchi" <a.bianchi at skynet.it>
> To: users at ovirt.org
> Sent: Wednesday, October 30, 2013 12:49:27 PM
> Subject: Re: [Users] Gluster VM stuck in "waiting for launch" state

> Thank you for your answer: yes it's marked as up

> > > From: "Alessandro Bianchi" <a.bianchi at skynet.it> To: users at ovirt.org
> > > Sent:
> > > Wednesday, October 30, 2013 12:34:21 PM
> > 
> 
> > > Subject: [Users] Gluster VM stuck in "waiting for launch" state
> > 
> 

> > > Hi everyone
> > 
> 

> > > I've set up a gluster storage with two replicated bricks
> > 
> 

> > > DC is up and I created a VM to test gluster storage
> > 
> 

> > > If I start the VM WITHOUT any disk attached (only one virtual DVD) it
> > > starts
> > 
> 
> > > fine.
> > 
> 

> > > If I attach a gluster domain disk thin provisioning 30 Gb the Vm stucks
> > > in
> > 
> 
> > > "waiting for launch" state
> > 
> 

> > > I see no special activity on the gluster servers (they serve several
> > > other
> > 
> 
> > > shares with no troubles at all and even the ISO domain is a NFS on
> > > locally
> > 
> 
> > > mounted gluster and works fine)
> > 
> 

> > > I've double checked all the pre requisites and they look fine (F 19 -
> > > gluster
> > 
> 
> > > setup insecure in both glusterd.vol and volume options - uid/gid/insecure
> > > )
> > 
> 

> > > Am I doing something wrong?
> > 
> 

> > > I'm even unable to stop the VM from the engine GUI
> > 
> 

> > > Any advise?
> > 
> 

> > what is the status of the host that runs the vm?
> 
> > is it up?
> 

> Yes

greate what does vdsClient returns for this vm status? 
(you can use: 
vdsClient -s 0 list table 
or if you work in non-secure setup: 
vdsClient 0 list table 
) 

> > > Thank you
> > 
> 

> > > Best regards
> > 
> 

> > > CentOS_30.log
> > 
> 

> > > 2013-10-30 10:17:48.094+0000: starting up
> > 
> 
> > > LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin
> > 
> 
> > > QEMU_AUDIO_DRV=spice /usr/bin/qemu-kvm -name CentOS_30 -S -machine
> > 
> 
> > > pc-1.0,accel=kvm,usb=off -cpu Westmere -m 2048 -smp
> > 
> 
> > > 1,sockets=1,cores=1,threads=1 -uuid 200dfb05-461e-49d9-95a2-c0a7c7ced669
> > 
> 
> > > -smbios type=1,manufacturer=oVirt,product=oVirt
> > 
> 
> > > Node,version=19-4,serial=316140A0-D7DA-11DD-AF75-08606ED667F7,uuid=200dfb05-461e-49d9-95a2-c0a7c7ced669
> > 
> 
> > > -no-user-config -nodefaults -chardev
> > 
> 
> > > socket,id=charmonitor,path=/var/lib/libvirt/qemu/CentOS_30.monitor,server,nowait
> > 
> 
> > > -mon chardev=charmonitor,id=monitor,mode=control -rtc
> > 
> 
> > > base=2013-10-30T10:17:47,driftfix=slew -no-shutdown -device
> > 
> 
> > > piix3-usb-uhci,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=/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/images/11111111-1111-1111-1111-111111111111/CentOS-6.4-x86_64-bin-DVD1.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=gluster://172.16.0.100/vms/21e3d67f-fdec-4f87-b09e-53af994a6f87/images/b73a79fe-401b-434c-b023-6de4c3eb100d/202adc86-7857-40eb-8ca6-7cec3ef0d2d6,if=none,id=drive-virtio-disk0,format=raw,serial=b73a79fe-401b-434c-b023-6de4c3eb100d,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,bootindex=2
> > 
> 
> > > -netdev tap,fd=27,id=hostnet0,vhost=on,vhostfd=28 -device
> > 
> 
> > > virtio-net-pci,netdev=hostnet0,id=net0,mac=00:1a:4a:00:00:33,bus=pci.0,addr=0x3,bootindex=3
> > 
> 
> > > -chardev
> > 
> 
> > > socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/200dfb05-461e-49d9-95a2-c0a7c7ced669.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/200dfb05-461e-49d9-95a2-c0a7c7ced669.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 spicevmc,id=charchannel2,name=vdagent -device
> > 
> 
> > > virtserialport,bus=virtio-serial0.0,nr=3,chardev=charchannel2,id=channel2,name=com.redhat.spice.0
> > 
> 
> > > -spice
> > 
> 
> > > tls-port=5900,addr=0,x509-dir=/etc/pki/vdsm/libvirt-spice,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=smartcard,tls-channel=usbredir,seamless-migration=on
> > 
> 
> > > -k en-us -vga qxl -global qxl-vga.ram_size=67108864 -global
> > 
> 
> > > qxl-vga.vram_size=67108864 -device virtio-balloon-pci,id=balloon0,bus=pci
> > 
> 

> > > vdsm.log
> > 
> 

> > > Thread-1239::DEBUG::2013-10-30
> > 
> 
> > > 11:25:03,420::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`d891f3d3-070d-403f-9050-f10651a7fc47`::ref 0 aborting False
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:04,982::domainMonitor::178::Storage.DomainMonitorThread::(_monitorDomain)
> > 
> 
> > > Refreshing domain 21e3d67f-fdec-4f87-b09e-53af994a6f87
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:04,992::fileSD::153::Storage.StorageDomain::(__init__) Reading
> > > domain
> > 
> 
> > > in path
> > 
> 
> > > /rhev/data-center/mnt/glusterSD/172.16.0.100:vms/21e3d67f-fdec-4f87-b09e-53af994a6f87
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:04,994::persistentDict::192::Storage.PersistentDict::(__init__)
> > 
> 
> > > Created a persistent dict with FileMetadataRW backend
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,005::persistentDict::234::Storage.PersistentDict::(refresh) read
> > 
> 
> > > lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=vms',
> > 
> 
> > > 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
> > 
> 
> > > 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
> > 
> 
> > > 'POOL_DESCRIPTION=GlusterSD',
> > 
> 
> > > 'POOL_DOMAINS=21e3d67f-fdec-4f87-b09e-53af994a6f87:Active,8e56a914-3395-48ad-ab4c-c2ca7f9956b4:Active',
> > 
> 
> > > 'POOL_SPM_ID=1', 'POOL_SPM_LVER=3',
> > 
> 
> > > 'POOL_UUID=e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > 'REMOTE_PATH=172.16.0.100:vms', 'ROLE=Master',
> > 
> 
> > > 'SDUUID=21e3d67f-fdec-4f87-b09e-53af994a6f87', 'TYPE=GLUSTERFS',
> > 
> 
> > > 'VERSION=3', '_SHA_CKSUM=2d0dc3836063d45dd1d8046aaf00bce05c2455ea']
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,008::fileSD::535::Storage.StorageDomain::(imageGarbageCollector)
> > 
> 
> > > Removing remnants of deleted images []
> > 
> 
> > > Thread-242:: INFO::2013-10-30
> > > 11:25:05,008::sd::374::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 21e3d67f-fdec-4f87-b09e-53af994a6f87_imageNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-242:: INFO::2013-10-30
> > > 11:25:05,008::sd::382::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 21e3d67f-fdec-4f87-b09e-53af994a6f87_volumeNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,020::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/glusterSD/172.16.0.100:vms/21e3d67f-fdec-4f87-b09e-53af994a6f87/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,026::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n497 bytes (497 B) copied,
> > 
> 
> > > 0.000280701 s, 1.8 MB/s\n'; <rc> = 0
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,721::domainMonitor::178::Storage.DomainMonitorThread::(_monitorDomain)
> > 
> 
> > > Refreshing domain 8e56a914-3395-48ad-ab4c-c2ca7f9956b4
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,730::fileSD::153::Storage.StorageDomain::(__init__) Reading
> > > domain
> > 
> 
> > > in path
> > 
> 
> > > /rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,731::persistentDict::192::Storage.PersistentDict::(__init__)
> > 
> 
> > > Created a persistent dict with FileMetadataRW backend
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,740::persistentDict::234::Storage.PersistentDict::(refresh) read
> > 
> 
> > > lines (FileMetadataRW)=['CLASS=Iso', 'DESCRIPTION=ISO',
> > > 'IOOPTIMEOUTSEC=1',
> > 
> 
> > > 'LEASERETRIES=3', 'LEASETIMESEC=5', 'LOCKPOLICY=',
> > 
> 
> > > 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=0',
> > 
> 
> > > 'POOL_UUID=01b79582-75e3-436d-bade-db653207620b,e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > 'REMOTE_PATH=172.16.0.5:/home/iso2', 'ROLE=Regular',
> > 
> 
> > > 'SDUUID=8e56a914-3395-48ad-ab4c-c2ca7f9956b4', 'TYPE=NFS', 'VERSION=0',
> > 
> 
> > > '_SHA_CKSUM=b0d102325f279bb8efa68c594cbace0b11c66783']
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,741::fileSD::535::Storage.StorageDomain::(imageGarbageCollector)
> > 
> 
> > > Removing remnants of deleted images []
> > 
> 
> > > Thread-243:: INFO::2013-10-30
> > > 11:25:07,741::sd::374::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 8e56a914-3395-48ad-ab4c-c2ca7f9956b4_imageNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-243:: INFO::2013-10-30
> > > 11:25:07,741::sd::382::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 8e56a914-3395-48ad-ab4c-c2ca7f9956b4_volumeNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,757::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,760::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n373 bytes (373 B) copied,
> > 
> 
> > > 0.000128829 s, 2.9 MB/s\n'; <rc> = 0
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,944::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::moving from state init ->
> > > state
> > 
> 
> > > preparing
> > 
> 
> > > Thread-1246:: INFO::2013-10-30
> > > 11:25:09,944::logUtils::44::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > repoStats(options=None)
> > 
> 
> > > Thread-1246:: INFO::2013-10-30
> > > 11:25:09,945::logUtils::47::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > repoStats, Return response: {'21e3d67f-fdec-4f87-b09e-53af994a6f87':
> > 
> 
> > > {'delay': '0.000280701', 'lastCheck': '4.9', 'code': 0, 'valid': True,
> > 
> 
> > > 'version': 3}, '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'delay':
> > 
> 
> > > '0.000128829', 'lastCheck': '2.2', 'code': 0, 'valid': True, 'version':
> > > 0}}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::task::1168::TaskManager.Task::(prepare)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::finished:
> > 
> 
> > > {'21e3d67f-fdec-4f87-b09e-53af994a6f87': {'delay': '0.000280701',
> > 
> 
> > > 'lastCheck': '4.9', 'code': 0, 'valid': True, 'version': 3},
> > 
> 
> > > '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'delay': '0.000128829',
> > 
> 
> > > 'lastCheck': '2.2', 'code': 0, 'valid': True, 'version': 0}}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::moving from state preparing
> > > ->
> > 
> 
> > > state finished
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > 
> 
> > > Owner.releaseAll requests {} resources {}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > 
> 
> > > Owner.cancelAll requests {}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::ref 0 aborting False
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,507::BindingXMLRPC::177::vds::(wrapper) client [172.16.0.5]
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,507::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::moving from state init ->
> > > state
> > 
> 
> > > preparing
> > 
> 
> > > Thread-1249:: INFO::2013-10-30
> > > 11:25:13,507::logUtils::44::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getSpmStatus(spUUID='e3cb7694-47f7-4eac-9201-922e381a25dc', options=None)
> > 
> 
> > > Thread-1249:: INFO::2013-10-30
> > > 11:25:13,508::logUtils::47::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus':
> > > 'SPM',
> > 
> 
> > > 'spmLver': 3}}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::task::1168::TaskManager.Task::(prepare)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::finished: {'spm_st':
> > > {'spmId':
> > 
> 
> > > 1, 'spmStatus': 'SPM', 'spmLver': 3}}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::moving from state preparing
> > > ->
> > 
> 
> > > state finished
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > 
> 
> > > Owner.releaseAll requests {} resources {}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > 
> 
> > > Owner.cancelAll requests {}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::ref 0 aborting False
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,510::BindingXMLRPC::177::vds::(wrapper) client [172.16.0.5]
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,510::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::moving from state init ->
> > > state
> > 
> 
> > > preparing
> > 
> 
> > > Thread-1250:: INFO::2013-10-30
> > > 11:25:13,511::logUtils::44::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getStoragePoolInfo(spUUID='e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > options=None)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::197::ResourceManager.Request::(__init__)
> > 
> 
> > > ResName=`Storage.e3cb7694-47f7-4eac-9201-922e381a25dc`ReqID=`42f323ef-aa03-49e6-893f-0e4ff0764b6b`::Request
> > 
> 
> > > was made in '/usr/share/vdsm/storage/hsm.py' line '2560' at
> > 
> 
> > > 'getStoragePoolInfo'
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::541::ResourceManager::(registerResource)
> > 
> 
> > > Trying to register resource
> > > 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc'
> > 
> 
> > > for lock type 'shared'
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::600::ResourceManager::(registerResource)
> > 
> 
> > > Resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc' is free. Now
> > > locking
> > 
> 
> > > as 'shared' (1 active user)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::237::ResourceManager.Request::(grant)
> > 
> 
> > > ResName=`Storage.e3cb7694-47f7-4eac-9201-922e381a25dc`ReqID=`42f323ef-aa03-49e6-893f-0e4ff0764b6b`::Granted
> > 
> 
> > > request
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,512::task::811::TaskManager.Task::(resourceAcquired)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::_resourcesAcquired:
> > 
> 
> > > Storage.e3cb7694-47f7-4eac-9201-922e381a25dc (shared)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,512::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::ref 1 aborting False
> > 
> 
> > > Thread-1250:: INFO::2013-10-30
> > > 11:25:13,517::logUtils::47::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
> > > 'master_uuid':
> > 
> 
> > > '21e3d67f-fdec-4f87-b09e-53af994a6f87', 'name': 'GlusterSD', 'version':
> > > '3',
> > 
> 
> > > 'domains':
> > 
> 
> > > '21e3d67f-fdec-4f87-b09e-53af994a6f87:Active,8e56a914-3395-48ad-ab4c-c2ca7f9956b4:Active',
> > 
> 
> > > 'pool_status': 'connected', 'isoprefix':
> > 
> 
> > > '/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/images/11111111-1111-1111-1111-111111111111',
> > 
> 
> > > 'type': 'GLUSTERFS', 'master_ver': 1, 'lver': 3}, 'dominfo':
> > 
> 
> > > {'21e3d67f-fdec-4f87-b09e-53af994a6f87': {'status': 'Active', 'diskfree':
> > 
> 
> > > '239969632256', 'alerts': [], 'version': 3, 'disktotal': '492120440832'},
> > 
> 
> > > '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'status': 'Active', 'diskfree':
> > 
> 
> > > '201653747712', 'alerts': [], 'version': 0, 'disktotal':
> > > '246783410176'}}}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,517::task::1168::TaskManager.Task::(prepare)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::finished: {'info':
> > > {'spm_id':
> > 
> 
> > > 1, 'master_uuid': '21e3d67f-fdec-4f87-b09e-53af994a6f87', 'name':
> > 
> 
> > > 'GlusterSD', 'version': '3', 'domains':
> > 
> 
> > > '21e3d67f-fdec-4f87-b09e-53af994a6f87:Active,8e56a914-3395-48ad-ab4c-c2ca7f9956b4:Active',
> > 
> 
> > > 'pool_status': 'connected', 'isoprefix':
> > 
> 
> > > '/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/images/11111111-1111-1111-1111-111111111111',
> > 
> 
> > > 'type': 'GLUSTERFS', 'master_ver': 1, 'lver': 3}, 'dominfo':
> > 
> 
> > > {'21e3d67f-fdec-4f87-b09e-53af994a6f87': {'status': 'Active', 'diskfree':
> > 
> 
> > > '239969632256', 'alerts': [], 'version': 3, 'disktotal': '492120440832'},
> > 
> 
> > > '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'status': 'Active', 'diskfree':
> > 
> 
> > > '201653747712', 'alerts': [], 'version': 0, 'disktotal':
> > > '246783410176'}}}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,517::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::moving from state preparing
> > > ->
> > 
> 
> > > state finished
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,517::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > 
> 
> > > Owner.releaseAll requests {} resources
> > 
> 
> > > {'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc': < ResourceRef
> > 
> 
> > > 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc', isValid: 'True' obj:
> > 
> 
> > > 'None'>}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > 
> 
> > > Owner.cancelAll requests {}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::615::ResourceManager::(releaseResource)
> > 
> 
> > > Trying to release resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc'
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::634::ResourceManager::(releaseResource)
> > 
> 
> > > Released resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc' (0
> > > active
> > 
> 
> > > users)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::640::ResourceManager::(releaseResource)
> > 
> 
> > > Resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc' is free, finding
> > > out
> > 
> 
> > > if anyone is waiting for it.
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::648::ResourceManager::(releaseResource) No
> > 
> 
> > > one is waiting for resource
> > > 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > Clearing records.
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::ref 0 aborting False
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:15,046::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/glusterSD/172.16.0.100:vms/21e3d67f-fdec-4f87-b09e-53af994a6f87/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:15,051::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n497 bytes (497 B) copied,
> > 
> 
> > > 0.00032077 s, 1.5 MB/s\n'; <rc> = 0
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:17,777::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:17,780::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n373 bytes (373 B) copied,
> > 
> 
> > > 9.9232e-05 s, 3.8 Thread-1239::DEBUG::2013-10-30
> > 
> 
> > > 11:25:03,420::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`d891f3d3-070d-403f-9050-f10651a7fc47`::ref 0 aborting False
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:04,982::domainMonitor::178::Storage.DomainMonitorThread::(_monitorDomain)
> > 
> 
> > > Refreshing domain 21e3d67f-fdec-4f87-b09e-53af994a6f87
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:04,992::fileSD::153::Storage.StorageDomain::(__init__) Reading
> > > domain
> > 
> 
> > > in path
> > 
> 
> > > /rhev/data-center/mnt/glusterSD/172.16.0.100:vms/21e3d67f-fdec-4f87-b09e-53af994a6f87
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:04,994::persistentDict::192::Storage.PersistentDict::(__init__)
> > 
> 
> > > Created a persistent dict with FileMetadataRW backend
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,005::persistentDict::234::Storage.PersistentDict::(refresh) read
> > 
> 
> > > lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=vms',
> > 
> 
> > > 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
> > 
> 
> > > 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
> > 
> 
> > > 'POOL_DESCRIPTION=GlusterSD',
> > 
> 
> > > 'POOL_DOMAINS=21e3d67f-fdec-4f87-b09e-53af994a6f87:Active,8e56a914-3395-48ad-ab4c-c2ca7f9956b4:Active',
> > 
> 
> > > 'POOL_SPM_ID=1', 'POOL_SPM_LVER=3',
> > 
> 
> > > 'POOL_UUID=e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > 'REMOTE_PATH=172.16.0.100:vms', 'ROLE=Master',
> > 
> 
> > > 'SDUUID=21e3d67f-fdec-4f87-b09e-53af994a6f87', 'TYPE=GLUSTERFS',
> > 
> 
> > > 'VERSION=3', '_SHA_CKSUM=2d0dc3836063d45dd1d8046aaf00bce05c2455ea']
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,008::fileSD::535::Storage.StorageDomain::(imageGarbageCollector)
> > 
> 
> > > Removing remnants of deleted images []
> > 
> 
> > > Thread-242:: INFO::2013-10-30
> > > 11:25:05,008::sd::374::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 21e3d67f-fdec-4f87-b09e-53af994a6f87_imageNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-242:: INFO::2013-10-30
> > > 11:25:05,008::sd::382::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 21e3d67f-fdec-4f87-b09e-53af994a6f87_volumeNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,020::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/glusterSD/172.16.0.100:vms/21e3d67f-fdec-4f87-b09e-53af994a6f87/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:05,026::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n497 bytes (497 B) copied,
> > 
> 
> > > 0.000280701 s, 1.8 MB/s\n'; <rc> = 0
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,721::domainMonitor::178::Storage.DomainMonitorThread::(_monitorDomain)
> > 
> 
> > > Refreshing domain 8e56a914-3395-48ad-ab4c-c2ca7f9956b4
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,730::fileSD::153::Storage.StorageDomain::(__init__) Reading
> > > domain
> > 
> 
> > > in path
> > 
> 
> > > /rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,731::persistentDict::192::Storage.PersistentDict::(__init__)
> > 
> 
> > > Created a persistent dict with FileMetadataRW backend
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,740::persistentDict::234::Storage.PersistentDict::(refresh) read
> > 
> 
> > > lines (FileMetadataRW)=['CLASS=Iso', 'DESCRIPTION=ISO',
> > > 'IOOPTIMEOUTSEC=1',
> > 
> 
> > > 'LEASERETRIES=3', 'LEASETIMESEC=5', 'LOCKPOLICY=',
> > 
> 
> > > 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=0',
> > 
> 
> > > 'POOL_UUID=01b79582-75e3-436d-bade-db653207620b,e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > 'REMOTE_PATH=172.16.0.5:/home/iso2', 'ROLE=Regular',
> > 
> 
> > > 'SDUUID=8e56a914-3395-48ad-ab4c-c2ca7f9956b4', 'TYPE=NFS', 'VERSION=0',
> > 
> 
> > > '_SHA_CKSUM=b0d102325f279bb8efa68c594cbace0b11c66783']
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,741::fileSD::535::Storage.StorageDomain::(imageGarbageCollector)
> > 
> 
> > > Removing remnants of deleted images []
> > 
> 
> > > Thread-243:: INFO::2013-10-30
> > > 11:25:07,741::sd::374::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 8e56a914-3395-48ad-ab4c-c2ca7f9956b4_imageNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-243:: INFO::2013-10-30
> > > 11:25:07,741::sd::382::Storage.StorageDomain::(_registerResourceNamespaces)
> > 
> 
> > > Resource namespace 8e56a914-3395-48ad-ab4c-c2ca7f9956b4_volumeNS already
> > 
> 
> > > registered
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,757::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:07,760::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n373 bytes (373 B) copied,
> > 
> 
> > > 0.000128829 s, 2.9 MB/s\n'; <rc> = 0
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,944::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::moving from state init ->
> > > state
> > 
> 
> > > preparing
> > 
> 
> > > Thread-1246:: INFO::2013-10-30
> > > 11:25:09,944::logUtils::44::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > repoStats(options=None)
> > 
> 
> > > Thread-1246:: INFO::2013-10-30
> > > 11:25:09,945::logUtils::47::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > repoStats, Return response: {'21e3d67f-fdec-4f87-b09e-53af994a6f87':
> > 
> 
> > > {'delay': '0.000280701', 'lastCheck': '4.9', 'code': 0, 'valid': True,
> > 
> 
> > > 'version': 3}, '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'delay':
> > 
> 
> > > '0.000128829', 'lastCheck': '2.2', 'code': 0, 'valid': True, 'version':
> > > 0}}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::task::1168::TaskManager.Task::(prepare)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::finished:
> > 
> 
> > > {'21e3d67f-fdec-4f87-b09e-53af994a6f87': {'delay': '0.000280701',
> > 
> 
> > > 'lastCheck': '4.9', 'code': 0, 'valid': True, 'version': 3},
> > 
> 
> > > '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'delay': '0.000128829',
> > 
> 
> > > 'lastCheck': '2.2', 'code': 0, 'valid': True, 'version': 0}}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::moving from state preparing
> > > ->
> > 
> 
> > > state finished
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > 
> 
> > > Owner.releaseAll requests {} resources {}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > 
> 
> > > Owner.cancelAll requests {}
> > 
> 
> > > Thread-1246::DEBUG::2013-10-30
> > 
> 
> > > 11:25:09,945::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`c064522b-6fe7-4cb2-b85d-ad1f8185919a`::ref 0 aborting False
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,507::BindingXMLRPC::177::vds::(wrapper) client [172.16.0.5]
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,507::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::moving from state init ->
> > > state
> > 
> 
> > > preparing
> > 
> 
> > > Thread-1249:: INFO::2013-10-30
> > > 11:25:13,507::logUtils::44::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getSpmStatus(spUUID='e3cb7694-47f7-4eac-9201-922e381a25dc', options=None)
> > 
> 
> > > Thread-1249:: INFO::2013-10-30
> > > 11:25:13,508::logUtils::47::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus':
> > > 'SPM',
> > 
> 
> > > 'spmLver': 3}}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::task::1168::TaskManager.Task::(prepare)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::finished: {'spm_st':
> > > {'spmId':
> > 
> 
> > > 1, 'spmStatus': 'SPM', 'spmLver': 3}}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::moving from state preparing
> > > ->
> > 
> 
> > > state finished
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > 
> 
> > > Owner.releaseAll requests {} resources {}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > 
> 
> > > Owner.cancelAll requests {}
> > 
> 
> > > Thread-1249::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,508::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`8518162d-eb91-44aa-819a-354e05807cb9`::ref 0 aborting False
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,510::BindingXMLRPC::177::vds::(wrapper) client [172.16.0.5]
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,510::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::moving from state init ->
> > > state
> > 
> 
> > > preparing
> > 
> 
> > > Thread-1250:: INFO::2013-10-30
> > > 11:25:13,511::logUtils::44::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getStoragePoolInfo(spUUID='e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > options=None)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::197::ResourceManager.Request::(__init__)
> > 
> 
> > > ResName=`Storage.e3cb7694-47f7-4eac-9201-922e381a25dc`ReqID=`42f323ef-aa03-49e6-893f-0e4ff0764b6b`::Request
> > 
> 
> > > was made in '/usr/share/vdsm/storage/hsm.py' line '2560' at
> > 
> 
> > > 'getStoragePoolInfo'
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::541::ResourceManager::(registerResource)
> > 
> 
> > > Trying to register resource
> > > 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc'
> > 
> 
> > > for lock type 'shared'
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::600::ResourceManager::(registerResource)
> > 
> 
> > > Resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc' is free. Now
> > > locking
> > 
> 
> > > as 'shared' (1 active user)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,511::resourceManager::237::ResourceManager.Request::(grant)
> > 
> 
> > > ResName=`Storage.e3cb7694-47f7-4eac-9201-922e381a25dc`ReqID=`42f323ef-aa03-49e6-893f-0e4ff0764b6b`::Granted
> > 
> 
> > > request
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,512::task::811::TaskManager.Task::(resourceAcquired)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::_resourcesAcquired:
> > 
> 
> > > Storage.e3cb7694-47f7-4eac-9201-922e381a25dc (shared)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,512::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::ref 1 aborting False
> > 
> 
> > > Thread-1250:: INFO::2013-10-30
> > > 11:25:13,517::logUtils::47::dispatcher::(wrapper) Run and protect:
> > 
> 
> > > getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
> > > 'master_uuid':
> > 
> 
> > > '21e3d67f-fdec-4f87-b09e-53af994a6f87', 'name': 'GlusterSD', 'version':
> > > '3',
> > 
> 
> > > 'domains':
> > 
> 
> > > '21e3d67f-fdec-4f87-b09e-53af994a6f87:Active,8e56a914-3395-48ad-ab4c-c2ca7f9956b4:Active',
> > 
> 
> > > 'pool_status': 'connected', 'isoprefix':
> > 
> 
> > > '/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/images/11111111-1111-1111-1111-111111111111',
> > 
> 
> > > 'type': 'GLUSTERFS', 'master_ver': 1, 'lver': 3}, 'dominfo':
> > 
> 
> > > {'21e3d67f-fdec-4f87-b09e-53af994a6f87': {'status': 'Active', 'diskfree':
> > 
> 
> > > '239969632256', 'alerts': [], 'version': 3, 'disktotal': '492120440832'},
> > 
> 
> > > '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'status': 'Active', 'diskfree':
> > 
> 
> > > '201653747712', 'alerts': [], 'version': 0, 'disktotal':
> > > '246783410176'}}}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,517::task::1168::TaskManager.Task::(prepare)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::finished: {'info':
> > > {'spm_id':
> > 
> 
> > > 1, 'master_uuid': '21e3d67f-fdec-4f87-b09e-53af994a6f87', 'name':
> > 
> 
> > > 'GlusterSD', 'version': '3', 'domains':
> > 
> 
> > > '21e3d67f-fdec-4f87-b09e-53af994a6f87:Active,8e56a914-3395-48ad-ab4c-c2ca7f9956b4:Active',
> > 
> 
> > > 'pool_status': 'connected', 'isoprefix':
> > 
> 
> > > '/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/images/11111111-1111-1111-1111-111111111111',
> > 
> 
> > > 'type': 'GLUSTERFS', 'master_ver': 1, 'lver': 3}, 'dominfo':
> > 
> 
> > > {'21e3d67f-fdec-4f87-b09e-53af994a6f87': {'status': 'Active', 'diskfree':
> > 
> 
> > > '239969632256', 'alerts': [], 'version': 3, 'disktotal': '492120440832'},
> > 
> 
> > > '8e56a914-3395-48ad-ab4c-c2ca7f9956b4': {'status': 'Active', 'diskfree':
> > 
> 
> > > '201653747712', 'alerts': [], 'version': 0, 'disktotal':
> > > '246783410176'}}}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,517::task::579::TaskManager.Task::(_updateState)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::moving from state preparing
> > > ->
> > 
> 
> > > state finished
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,517::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > 
> 
> > > Owner.releaseAll requests {} resources
> > 
> 
> > > {'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc': < ResourceRef
> > 
> 
> > > 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc', isValid: 'True' obj:
> > 
> 
> > > 'None'>}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > 
> 
> > > Owner.cancelAll requests {}
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::615::ResourceManager::(releaseResource)
> > 
> 
> > > Trying to release resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc'
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::634::ResourceManager::(releaseResource)
> > 
> 
> > > Released resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc' (0
> > > active
> > 
> 
> > > users)
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::640::ResourceManager::(releaseResource)
> > 
> 
> > > Resource 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc' is free, finding
> > > out
> > 
> 
> > > if anyone is waiting for it.
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::resourceManager::648::ResourceManager::(releaseResource) No
> > 
> 
> > > one is waiting for resource
> > > 'Storage.e3cb7694-47f7-4eac-9201-922e381a25dc',
> > 
> 
> > > Clearing records.
> > 
> 
> > > Thread-1250::DEBUG::2013-10-30
> > 
> 
> > > 11:25:13,518::task::974::TaskManager.Task::(_decref)
> > 
> 
> > > Task=`221b537a-2c1b-418f-93ff-bf77d4029097`::ref 0 aborting False
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:15,046::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/glusterSD/172.16.0.100:vms/21e3d67f-fdec-4f87-b09e-53af994a6f87/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-242::DEBUG::2013-10-30
> > 
> 
> > > 11:25:15,051::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n497 bytes (497 B) copied,
> > 
> 
> > > 0.00032077 s, 1.5 MB/s\n'; <rc> = 0
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:17,777::fileSD::238::Storage.Misc.excCmd::(getReadDelay)
> > > '/usr/bin/dd
> > 
> 
> > > iflag=direct
> > 
> 
> > > if=/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/dom_md/metadata
> > 
> 
> > > bs=4096 count=1' (cwd None)
> > 
> 
> > > Thread-243::DEBUG::2013-10-30
> > 
> 
> > > 11:25:17,780::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
> > 
> 
> > > <err> = '0+1 records in\n0+1 records out\n373 bytes (373 B) copied,
> > 
> 
> > > 9.9232e-05 s, 3.8 MB/s\n'; <rc> = 0
> > 
> 

> > > engine.log
> > 
> 

> > > 2013-10-30 11:17:47,729 INFO [org.ovirt.engine.core.bll.RunVmOnceCommand]
> > 
> 
> > > (ajp--127.0.0.1-8702-6) Running command: RunVmOnceCommand internal:
> > > false.
> > 
> 
> > > Entities affected : ID: 200dfb05-461e-49d9-95a2-c0a7c7ced669 Type: VM
> > 
> 
> > > 2013-10-30 11:17:47,743 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> > > (ajp--127.0.0.1-8702-6)
> > 
> 
> > > START, CreateVmVDSCommand(HostName = Hypervisor, HostId =
> > 
> 
> > > da764821-0650-40f0-b7cf-038766fbd2ca,
> > 
> 
> > > vmId=200dfb05-461e-49d9-95a2-c0a7c7ced669, vm=VM [CentOS_30]), log id:
> > 
> 
> > > 638a3a0e
> > 
> 
> > > 2013-10-30 11:17:47,765 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> > 
> 
> > > (ajp--127.0.0.1-8702-6) START, CreateVDSCommand(HostName = Hypervisor,
> > 
> 
> > > HostId = da764821-0650-40f0-b7cf-038766fbd2ca,
> > 
> 
> > > vmId=200dfb05-461e-49d9-95a2-c0a7c7ced669, vm=VM [CentOS_30]), log id:
> > 
> 
> > > 297dbca2
> > 
> 
> > > 2013-10-30 11:17:47,784 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> > 
> 
> > > (ajp--127.0.0.1-8702-6)
> > 
> 
> > > org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
> > 
> 
> > > spiceSslCipherSuite=DEFAULT,memSize=2048,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=pc-1.0,keyboardLayout=en-us,memGuaranteedSize=1365,pitReinjection=false,nice=0,display=qxl,smartcardEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=0,transparentHugePages=true,vmId=200dfb05-461e-49d9-95a2-c0a7c7ced669,devices=[Ljava.util.HashMap;@f3eee3e,acpiEnable=true,vmName=CentOS_30,cpuType=Westmere,custom={}
> > 
> 
> > > 2013-10-30 11:17:47,785 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> > 
> 
> > > (ajp--127.0.0.1-8702-6) FINISH, CreateVDSCommand, log id: 297dbca2
> > 
> 
> > > 2013-10-30 11:17:47,786 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> > > (ajp--127.0.0.1-8702-6)
> > 
> 
> > > FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 638a3a0e
> > 
> 
> > > 2013-10-30 11:17:47,812 INFO
> > 
> 
> > > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> > 
> 
> > > (ajp--127.0.0.1-8702-6) Correlation ID: 4f8bc4f9, Job ID:
> > 
> 
> > > 74a77fc0-7e83-44c0-b3d7-334eb38612b4, Call Stack: null, Custom Event ID:
> > > -1,
> > 
> 
> > > Message: VM CentOS_30 was started by admin at internal (Host: Hypervisor).
> > 
> 
> > > 2013-10-30 11:17:51,115 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand]
> > 
> 
> > > (DefaultQuartzScheduler_Worker-37) START, FullListVdsCommand(HostName =
> > 
> 
> > > Hypervisor, HostId = da764821-0650-40f0-b7cf-038766fbd2ca,
> > 
> 
> > > vds=Host[Hypervisor], vmIds=[200dfb05-461e-49d9-95a2-c0a7c7ced669]), log
> > > id:
> > 
> 
> > > 546bd3e2
> > 
> 
> > > 2013-10-30 11:17:51,119 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand]
> > 
> 
> > > (DefaultQuartzScheduler_Worker-37) FINISH, FullListVdsCommand, return:
> > 
> 
> > > [Ljava.util.HashMap;@318a7164, log id: 546bd3e2
> > 
> 
> > > 2013-10-30 11:17:51,121 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> > 
> 
> > > (DefaultQuartzScheduler_Worker-37) Received a scsi Device without an
> > > address
> > 
> 
> > > when processing VM 200dfb05-461e-49d9-95a2-c0a7c7ced669 devices, skipping
> > 
> 
> > > device: {model=virtio-scsi, device=scsi, type=controller}
> > 
> 
> > > 2013-10-30 11:17:51,121 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> > 
> 
> > > (DefaultQuartzScheduler_Worker-37) Received a cdrom Device without an
> > 
> 
> > > address when processing VM 200dfb05-461e-49d9-95a2-c0a7c7ced669 devices,
> > 
> 
> > > skipping device: {shared=false, bootOrder=1, iface=ide, index=2,
> > 
> 
> > > specParams={}, device=cdrom,
> > 
> 
> > > path=/rhev/data-center/mnt/172.16.0.5:_home_iso2/8e56a914-3395-48ad-ab4c-c2ca7f9956b4/images/11111111-1111-1111-1111-111111111111/CentOS-6.4-x86_64-bin-DVD1.iso,
> > 
> 
> > > type=disk, readonly=true, deviceId=e29c7ac7-f872-43e3-90e2-cb2205c0203f}
> > 
> 
> > > 2013-10-30 11:17:51,122 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> > 
> 
> > > (DefaultQuartzScheduler_Worker-37) Received a disk Device without an
> > > address
> > 
> 
> > > when processing VM 200dfb05-461e-49d9-95a2-c0a7c7ced669 devices, skipping
> > 
> 
> > > device: {shared=false, volumeID=202adc86-7857-40eb-8ca6-7cec3ef0d2d6,
> > 
> 
> > > index=0, propagateErrors=off, format=raw, type=disk, truesize=4096,
> > 
> 
> > > reqsize=0, bootOrder=2, iface=virtio,
> > 
> 
> > > volumeChain=[Ljava.lang.Object;@8741843,
> > 
> 
> > > imageID=b73a79fe-401b-434c-b023-6de4c3eb100d,
> > 
> 
> > > domainID=21e3d67f-fdec-4f87-b09e-53af994a6f87, specParams={},
> > 
> 
> > > optional=false, volumeInfo={volfileServer=172.16.0.100, volPort=0,
> > 
> 
> > > protocol=gluster, volTransport=tcp,
> > 
> 
> > > path=vms/21e3d67f-fdec-4f87-b09e-53af994a6f87/images/b73a79fe-401b-434c-b023-6de4c3eb100d/202adc86-7857-40eb-8ca6-7cec3ef0d2d6,
> > 
> 
> > > volType=network},
> > 
> 
> > > path=/rhev/data-center/e3cb7694-47f7-4eac-9201-922e381a25dc/21e3d67f-fdec-4f87-b09e-53af994a6f87/images/b73a79fe-401b-434c-b023-6de4c3eb100d/202adc86-7857-40eb-8ca6-7cec3ef0d2d6,
> > 
> 
> > > device=disk, poolID=e3cb7694-47f7-4eac-9201-922e381a25dc, readonly=false,
> > 
> 
> > > deviceId=b73a79fe-401b-434c-b023-6de4c3eb100d, apparentsize=32212254720}
> > 
> 
> > > 2013-10-30 11:17:51,123 INFO
> > 
> 
> > > [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> > 
> 
> > > (DefaultQuartzScheduler_Worker-37) Received a memballoon Device without
> > > an
> > 
> 
> > > address when processing VM 200dfb05-461e-49d9-95a2-c0a7c7ced669 devices,
> > 
> 
> > > skipping device: {specParams={model=virtio}, target=2097152,
> > 
> 
> > > device=memballoon, type=balloon,
> > 
> 
> > > deviceId=b61b058d-cdfe-4d7c-8e6c-1bfd631cb26c}
> > 
> 

> > > _______________________________________________
> > 
> 
> > > Users mailing list Users at ovirt.org
> > > http://lists.ovirt.org/mailman/listinfo/users
> > 
> 

> > -------------- next part --------------
> 
> > An HTML attachment was scrubbed...
> 
> > URL:
> > <http://lists.ovirt.org/pipermail/users/attachments/20131030/e471743e/attachment.html>
> > ------------------------------
> 

> > _______________________________________________
> 
> > Users mailing list Users at ovirt.org
> > http://lists.ovirt.org/mailman/listinfo/users End of Users Digest, Vol 25,
> > Issue 140
> 
> > **************************************
> 

> --

> SkyNet SRL

> Via Maggiate 67/a - 28021 Borgomanero (NO) - tel. +39 0322-836487/834765 -
> fax +39 0322-836608

> http://www.skynet.it

> Autorizzazione Ministeriale n.197

> Le informazioni contenute in questo messaggio sono riservate e confidenziali
> ed è vietata la diffusione in qualunque modo eseguita.
> Qualora Lei non fosse la persona a cui il presente messaggio è destinato, La
> invitiamo ad eliminarlo ed a distruggerlo non divulgandolo, dandocene
> gentilmente comunicazione.
> Per qualsiasi informazione si prega di contattare info at skynet.it (e-mail
> dell'azienda). Rif. D.L. 196/2003

> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20131030/e613bee9/attachment-0001.html>