[Users] unable to start vm in 3.3 and f19 with gluster

Tue Sep 24 23:10:21 UTC 2013

Hello,
I'm testing GlusterFS on 3.3 with fedora 19 systems.
One engine (ovirt) + 2 nodes (ovnode01 and ovnode02)

Successfully created gluster volume composed by two bricks (one for
each vdsm node) distributed replicated

Suggestion:
If page
http://www.ovirt.org/Features/GlusterFS_Storage_Domain
is the reference, perhaps it would be better to explicitly specify
that one has to start the created volume before going to add a storage
domain based on the created volume.
Not knowing Gluster could lead to think that the start phase is
responsibility of storage domain creation itself ...

All seems ok from a configuration point of view.
Uploaded a CentOS 6.4 iso image ito my ISO_DOMAIN (nfs exported from
engine.. this will be another thread...)
Created a server VM with 10Gb of disk with thin allocation.

I get an error when starting the VM

on engine.log
2013-09-25 00:43:16,027 ERROR
[org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
(DefaultQuartzScheduler_Worker-44) Rerun vm
409c5dbe-5e70-40de-bf73-46ef484ea2d7. Called from vds ovnode02
2013-09-25 00:43:16,031 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(pool-6-thread-48) Correlation ID: 5ea15175, Job ID:
48128550-3633-4da4-8d9c-ab704be02f02, Call Stack: null, Custom Event
ID: -1, Message: Failed to run VM C6 on Host ovnode02.
2013-09-25 00:43:16,057 INFO  [org.ovirt.engine.core.bll.RunVmCommand]
(pool-6-thread-48) Lock Acquired to object EngineLock [exclusiveLocks=
key: 409c5dbe-5e70-40de-bf73-46ef484ea2d7 value: VM
, sharedLocks= ]
2013-09-25 00:43:16,070 INFO
[org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
(pool-6-thread-48) START, IsVmDuringInitiatingVDSCommand( vmId =
409c5dbe-5e70-40de-bf73-46ef484ea2d7), log id: 7979c53b
2013-09-25 00:43:16,071 INFO
[org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
(pool-6-thread-48) FINISH, IsVmDuringInitiatingVDSCommand, return:
false, log id: 7979c53b
2013-09-25 00:43:16,086 INFO  [org.ovirt.engine.core.bll.RunVmCommand]
(pool-6-thread-48) Running command: RunVmCommand internal: false.
Entities affected :  ID: 409c5dbe-5e70-40de-bf73-46ef484ea2d7 Type: VM
2013-09-25 00:43:16,110 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IsoPrefixVDSCommand]
(pool-6-thread-48) START, IsoPrefixVDSCommand( storagePoolId =
6b3175e6-6fa2-473f-ba21-38917c413ba9, ignoreFailoverLimit = false),
log id: 7fd62f0f
2013-09-25 00:43:16,111 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IsoPrefixVDSCommand]
(pool-6-thread
...

On node vdsm.log
Thread-2915::ERROR::2013-09-25
00:43:20,108::vm::2062::vm.Vm::(_startUnderlyingVm)
vmId=`409c5dbe-5e70-40de-bf73-46ef484ea2d7`::The vm start process
failed
Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 2022, in _startUnderlyingVm
    self._run()
  File "/usr/share/vdsm/vm.py", line 2906, in _run
    self._connection.createXML(domxml, flags),
  File "/usr/lib64/python2.7/site-packages/vdsm/libvirtconnection.py",
line 76, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 2805, in createXML
    if ret is None:raise libvirtError('virDomainCreateXML() failed', conn=self)
libvirtError: Unable to read from monitor: Connection reset by peer
Thread-2915::DEBUG::2013-09-25
00:43:20,176::vm::2448::vm.Vm::(setDownStatus)
vmId=`409c5dbe-5e70-40de-bf73-46ef484ea2d7`::Changed state to Down:
Unable to read from monitor: Connection reset by peer
libvirtEventLoop::WARNING::2013-09-25
00:43:20,114::clientIF::337::vds::(teardownVolumePath) Drive is not a
vdsm image: VOLWM_CHUNK_MB:1024 VOLWM_CHUNK_REPLICATE_MULT:2
VOLWM_FREE_PCT:50 _blockDev:False _checkIoTuneCategories:<bound method
Drive._checkIoTuneCategories of <vm.Drive object at 0x2b12950>>
_customize:<bound method Drive._customize of <vm.Drive object at
0x2b12950>> _deviceXML:<disk device="cdrom" snapshot="no"
type="file"><source
file="/var/run/vdsm/payload/409c5dbe-5e70-40de-bf73-46ef484ea2d7.393db1d8c9e756483db001b30a239296.img"
startupPolicy="optional"/><target bus="ide"
dev="hdd"/><readonly/><serial></serial></disk> _makeName:<bound method
Drive._makeName of <vm.Drive object at 0x2b12950>>
_validateIoTuneParams:<bound method Drive._validateIoTuneParams of
<vm.Drive object at 0x2b12950>> apparentsize:0 blockDev:False
cache:none conf:{'status': 'Down', 'acpiEnable': 'true',
'emulatedMachine': 'pc-1.0', 'vmId':
'409c5dbe-5e70-40de-bf73-46ef484ea2d7', 'pid': '0',
'memGuaranteedSize': 1365, 'timeOffset': '0', 'keyboardLayout':
'en-us', 'displayPort': '-1', 'displaySecurePort': '-1',
'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Nehalem', 'custom': {},
'clientIp': '', 'exitCode': 1, 'nicModel': 'rtl8139,pv',
'smartcardEnable': 'false', 'kvmEnable': 'true', 'pitReinjection':
'false', 'transparentHugePages': 'true', 'devices': [{'device':
'scsi', 'model': 'virtio-scsi', 'type': 'controller'}, {'device':
'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId':
'70eadea2-6b53-

Let me know if you need full logs

The disk image itself seems ok:

[root at ovnode02 ~]# ll
/rhev/data-center/mnt/glusterSD/ovnode01\:gv01/20042e7b-0929-48ca-ad40-2a2aa22f0689/images/d004045e-620b-4d90-8a7f-6c6d26393a08/
total 1025
-rw-rw----. 1 vdsm kvm 10737418240 Sep 25 00:42
dff09892-bc60-4de5-85c0-2a1fa215a161
-rw-rw----. 1 vdsm kvm     1048576 Sep 25 00:42
dff09892-bc60-4de5-85c0-2a1fa215a161.lease
-rw-r--r--. 1 vdsm kvm         268 Sep 25 00:42
dff09892-bc60-4de5-85c0-2a1fa215a161.meta

[root at ovnode02 ~]# qemu-img info
/rhev/data-center/mnt/glusterSD/ovnode01\:gv01/20042e7b-0929-48ca-ad40-2a2aa22f0689/images/d004045e-620b-4d90-8a7f-6c6d26393a08/dff09892-bc60-4de5-85c0-2a1fa215a161
image: /rhev/data-center/mnt/glusterSD/ovnode01:gv01/20042e7b-0929-48ca-ad40-2a2aa22f0689/images/d004045e-620b-4d90-8a7f-6c6d26393a08/dff09892-bc60-4de5-85c0-2a1fa215a161
file format: raw
virtual size: 10G (10737418240 bytes)
disk size: 0

Also on the other node
[root at ovnode01 vdsm]# ll
/rhev/data-center/mnt/glusterSD/ovnode01\:gv01/20042e7b-0929-48ca-ad40-2a2aa22f0689/images/d004045e-620b-4d90-8a7f-6c6d26393a08/
total 1025
-rw-rw----. 1 vdsm kvm 10737418240 Sep 25 00:42
dff09892-bc60-4de5-85c0-2a1fa215a161
-rw-rw----. 1 vdsm kvm     1048576 Sep 25 00:42
dff09892-bc60-4de5-85c0-2a1fa215a161.lease
-rw-r--r--. 1 vdsm kvm         268 Sep 25 00:42
dff09892-bc60-4de5-85c0-2a1fa215a161.meta

[root at ovnode01 vdsm]# qemu-img info
/rhev/data-center/mnt/glusterSD/ovnode01\:gv01/20042e7b-0929-48ca-ad40-2a2aa22f0689/images/d004045e-620b-4d90-8a7f-6c6d26393a08/dff09892-bc60-4de5-85c0-2a1fa215a161
image: /rhev/data-center/mnt/glusterSD/ovnode01:gv01/20042e7b-0929-48ca-ad40-2a2aa22f0689/images/d004045e-620b-4d90-8a7f-6c6d26393a08/dff09892-bc60-4de5-85c0-2a1fa215a161
file format: raw
virtual size: 10G (10737418240 bytes)
disk size: 0

[root at ovnode02 ~]# gluster volume list
gv01

[root at ovnode02 ~]# gluster volume info

Volume Name: gv01
Type: Replicate
Volume ID: 7cf18f87-eef8-47cb-b469-8e5f92bfcd98
Status: Started
Number of Bricks: 1 x 2 = 2
Transport-type: tcp
Bricks:
Brick1: 192.168.33.41:/export/brick1/sdb1
Brick2: 192.168.33.42:/export/brick1/sdb1
Options Reconfigured:
storage.owner-gid: 36
storage.owner-uid: 36
auth.allow: *
user.cifs: on
nfs.disable: off

I notice during the volume creation this message that I don't know if
could be of impact:

Volume Option group=virt could not be set on gv01

See also this image for events generated on egine gui.
https://docs.google.com/file/d/0BwoPbcrMv8mvZEp6UmhPV0ttaVU/edit?usp=sharing

Possibly the openstack related ones could be misunderstood and
sincerely I haven't understood their meaning....

Gianluca