Bug 1525098

Created attachment 1366783 [details]
engine , vdsm ,libvirt log

Description of problem:
I have 2 VM's with ISCSI /NFS /gluster FS's.
I started them all , only the gluster VM's failed to load.

Starting a VM booting from a gluster OS disk fails with VM_DOWN_ERROR(119), VM golden_env_mixed_virtio_3_0 is down with err or. Exit message: internal error: process exited while connecting to monitor: [2017-12-12 15:13:50.073633] I [afr.c:94:fix_quorum_o

I checked gluster storage & cluster peers are connected & volumes are in started mode so it looks ok to me .


Version-Release number of selected component (if applicable):
4.2.0-0.6
4.20.9-1

How reproducible:
100% so far ( tried it 3 times on 2 different engines )

Steps to Reproduce:
1.Import image as template from glance
2.create a VM from that image
3.Start the VM

Actual results:
Starting a VM booting from a gluster OS disk fails with VM_DOWN_ERROR(119), VM golden_env_mixed_virtio_3_0 is down with err or. Exit message: internal error: process exited while connecting to monitor: [2017-12-12 15:13:50.073633] I [afr.c:94:fix_quorum_o



Expected results:


Additional info:


Engine:
2017-12-12 17:14:02,533+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-11) [] EVENT_ID: VM_DOWN_ERROR(119), VM golden_env_mixed_virtio_3_0 is down with err
or. Exit message: internal error: process exited while connecting to monitor: [2017-12-12 15:13:50.073633] I [afr.c:94:fix_quorum_options] 0-storage_local_ge8_volume_0-replicate-0: reindeer: incoming qtype = non
e
[2017-12-12 15:13:50.073696] I [afr.c:116:fix_quorum_options] 0-storage_local_ge8_volume_0-replicate-0: reindeer: quorum_count = 2147483647
[2017-12-12 15:13:50.075961] W [MSGID: 101174] [graph.c:360:_log_if_unknown_option] 0-storage_local_ge8_volume_0-readdir-ahead: option 'parallel-readdir' is not recognized
[2017-12-12 15:13:50.076032] W [MSGID: 101174] [graph.c:360:_log_if_unknown_option] 0-storage_local_ge8_volume_0-client-2: option 'transport.socket.keepalive-count' is not recognized
[2017-12-12 15:13:50.076075] W [MSGID: 101174] [graph.c:360:_log_if_unknown_option] 0-storage_local_ge8_volume_0-client-1: option 'transport.socket.keepalive-count' is not recognized
[2017-12-12 15:13:50.076115] W [MSGID: 101174] [graph.c:360:_log_if_unknown_option] 0-storage_local_ge8_volume_0-client-0: option 'transport.socket.keepalive-count' .
2017-12-12 17:14:02,534+02 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] add VM '3dd85c97-0805-4ee4-bd6a-65d3edcb32b2'(golden_env_mixed_virtio_3_0) to rerun treatmen
t
2017-12-12 17:14:02,552+02 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.VmsMonitoring] (ForkJoinPool-1-worker-11) [] Rerun VM '3dd85c97-0805-4ee4-bd6a-65d3edcb32b2'. Called from VDS 'host_mixed_2'

vdsm.log:
017-12-12 17:20:17,630+0200 ERROR (vm/3dd85c97) [virt.vm] (vmId='3dd85c97-0805-4ee4-bd6a-65d3edcb32b2') The vm start process failed (vm:911)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 840, in _startUnderlyingVm
    self._run()
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 2707, in _run
    dom.createWithFlags(flags)
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line 126, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/utils.py", line 512, in wrapper
    return func(inst, *args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1069, in createWithFlags
    if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)


From the host qemu log :
/var/log/libvirt/qemu/golden_env_mixed_virtio_3_0.log
[2017-12-12 15:20:15.214704] W [MSGID: 114031] [client-rpc-fops.c:2211:client3_3_seek_cbk] 0-storage_local_ge8_volume_0-client-0: remote operation failed [No such device or address]
[2017-12-12 15:20:15.220185] I [MSGID: 114021] [client.c:2365:notify] 0-storage_local_ge8_volume_0-client-0: current graph is no longer active, destroying rpc_client 
[2017-12-12 15:20:15.220276] I [MSGID: 114021] [client.c:2365:notify] 0-storage_local_ge8_volume_0-client-1: current graph is no longer active, destroying rpc_client 
[2017-12-12 15:20:15.220336] I [MSGID: 114021] [client.c:2365:notify] 0-storage_local_ge8_volume_0-client-2: current graph is no longer active, destroying rpc_client 
[2017-12-12 15:20:15.220507] I [MSGID: 114018] [client.c:2280:client_rpc_notify] 0-storage_local_ge8_volume_0-client-0: disconnected from storage_local_ge8_volume_0-client-0. Client process will keep trying to connect to glusterd until brick's port is available
[2017-12-12 15:20:15.220555] I [MSGID: 114018] [client.c:2280:client_rpc_notify] 0-storage_local_ge8_volume_0-client-1: disconnected from storage_local_ge8_volume_0-client-1. Client process will keep trying to connect to glusterd until brick's port is available
[2017-12-12 15:20:15.220574] W [MSGID: 108001] [afr-common.c:4820:afr_notify] 0-storage_local_ge8_volume_0-replicate-0: Client-quorum is not met
[2017-12-12 15:20:15.221079] I [MSGID: 114018] [client.c:2280:client_rpc_notify] 0-storage_local_ge8_volume_0-client-2: disconnected from storage_local_ge8_volume_0-client-2. Client process will keep trying to connect to glusterd until brick's port is available
[2017-12-12 15:20:15.222347] E [MSGID: 108006] [afr-common.c:4731:afr_notify] 0-storage_local_ge8_volume_0-replicate-0: All subvolumes are down. Going offline until atleast one of them comes back up.
[2017-12-12 15:20:15.224054] I [io-stats.c:4043:fini] 0-storage_local_ge8_volume_0: io-stats translator unloaded
[2017-12-12 15:20:15.224855] I [MSGID: 101191] [event-epoll.c:633:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 2
[2017-12-12 15:20:15.225042] I [MSGID: 101191] [event-epoll.c:633:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 1
2017-12-12T15:20:16.095453Z qemu-kvm: -drive file=gluster://gluster01.scl.lab.tlv.redhat.com/storage_local_ge8_volume_0/e4bac178-6b0d-4e0c-8c6e-04203305ef77/images/1e779fb6-52cb-443f-9b27-0dee98d2267a/ba8bbf28-d8df-45c3-9177-0b6d831f826a,file.debug=4,format=qcow2,if=none,id=drive-virtio-disk0,serial=1e779fb6-52cb-443f-9b27-0dee98d2267a,cache=none,werror=stop,rerror=stop,aio=threads: Could not read L1 table: Input/output error
2017-12-12 15:20:16.125+0000: shutting down, reason=failed