[ovirt-users] VMs becoming non-responsive sporadically
nicolas at devels.es
nicolas at devels.es
Sun May 1 14:04:48 UTC 2016
El 2016-05-01 14:01, Nir Soffer escribió:
> On Sun, May 1, 2016 at 3:31 PM, <nicolas at devels.es> wrote:
>> El 2016-04-30 23:22, Nir Soffer escribió:
>>>
>>> On Sun, May 1, 2016 at 12:48 AM, <nicolas at devels.es> wrote:
>>>>
>>>> El 2016-04-30 22:37, Nir Soffer escribió:
>>>>>
>>>>>
>>>>> On Sat, Apr 30, 2016 at 10:28 PM, Nir Soffer <nsoffer at redhat.com>
>>>>> wrote:
>>>>>>
>>>>>>
>>>>>> On Sat, Apr 30, 2016 at 7:16 PM, <nicolas at devels.es> wrote:
>>>>>>>
>>>>>>>
>>>>>>> El 2016-04-30 16:55, Nir Soffer escribió:
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> On Sat, Apr 30, 2016 at 11:33 AM, Nicolás <nicolas at devels.es>
>>>>>>>> wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Hi Nir,
>>>>>>>>>
>>>>>>>>> El 29/04/16 a las 22:34, Nir Soffer escribió:
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> On Fri, Apr 29, 2016 at 9:17 PM, <nicolas at devels.es> wrote:
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> Hi,
>>>>>>>>>>>
>>>>>>>>>>> We're running oVirt 3.6.5.3-1 and lately we're experiencing
>>>>>>>>>>> some
>>>>>>>>>>> issues
>>>>>>>>>>> with
>>>>>>>>>>> some VMs being paused because they're marked as
>>>>>>>>>>> non-responsive.
>>>>>>>>>>> Mostly,
>>>>>>>>>>> after a few seconds they recover, but we want to debug
>>>>>>>>>>> precisely
>>>>>>>>>>> this
>>>>>>>>>>> problem so we can fix it consistently.
>>>>>>>>>>>
>>>>>>>>>>> Our scenario is the following:
>>>>>>>>>>>
>>>>>>>>>>> ~495 VMs, of which ~120 are constantly up
>>>>>>>>>>> 3 datastores, all of them iSCSI-based:
>>>>>>>>>>> * ds1: 2T, currently has 276 disks
>>>>>>>>>>> * ds2: 2T, currently has 179 disks
>>>>>>>>>>> * ds3: 500G, currently has 65 disks
>>>>>>>>>>> 7 hosts: All have mostly the same hardware. CPU and memory
>>>>>>>>>>> are
>>>>>>>>>>> currently
>>>>>>>>>>> very lowly used (< 10%).
>>>>>>>>>>>
>>>>>>>>>>> ds1 and ds2 are physically the same backend which exports
>>>>>>>>>>> two
>>>>>>>>>>> 2TB
>>>>>>>>>>> volumes.
>>>>>>>>>>> ds3 is a different storage backend where we're currently
>>>>>>>>>>> migrating
>>>>>>>>>>> some
>>>>>>>>>>> disks from ds1 and ds2.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> What the the storage backend behind ds1 and 2?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> The storage backend for ds1 and ds2 is the iSCSI-based HP
>>>>>>>>> LeftHand
>>>>>>>>> P4000
>>>>>>>>> G2.
>>>>>>>>>
>>>>>>>>>>> Usually, when VMs become unresponsive, the whole host where
>>>>>>>>>>> they
>>>>>>>>>>> run
>>>>>>>>>>> gets
>>>>>>>>>>> unresponsive too, so that gives a hint about the problem, my
>>>>>>>>>>> bet
>>>>>>>>>>> is
>>>>>>>>>>> the
>>>>>>>>>>> culprit is somewhere on the host side and not on the VMs
>>>>>>>>>>> side.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Probably the vm became unresponsive because connection to the
>>>>>>>>>> host
>>>>>>>>>> was
>>>>>>>>>> lost.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> I forgot to mention that less commonly we have situations where
>>>>>>>>> the
>>>>>>>>> host
>>>>>>>>> doesn't get unresponsive but the VMs on it do and they don't
>>>>>>>>> become
>>>>>>>>> responsive ever again, so we have to forcibly power them off
>>>>>>>>> and
>>>>>>>>> start
>>>>>>>>> them
>>>>>>>>> on a different host. But in this case the connection with the
>>>>>>>>> host
>>>>>>>>> doesn't
>>>>>>>>> ever get lost (so basically the host is Up, but any VM run on
>>>>>>>>> them
>>>>>>>>> is
>>>>>>>>> unresponsive).
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>>> When that
>>>>>>>>>>> happens, the host itself gets non-responsive and only
>>>>>>>>>>> recoverable
>>>>>>>>>>> after
>>>>>>>>>>> reboot, since it's unable to reconnect.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Piotr, can you check engine log and explain why host is not
>>>>>>>>>> reconnected?
>>>>>>>>>>
>>>>>>>>>>> I must say this is not specific to
>>>>>>>>>>> this oVirt version, when we were using v.3.6.4 the same
>>>>>>>>>>> happened,
>>>>>>>>>>> and
>>>>>>>>>>> it's
>>>>>>>>>>> also worthy mentioning we've not done any configuration
>>>>>>>>>>> changes
>>>>>>>>>>> and
>>>>>>>>>>> everything had been working quite well for a long time.
>>>>>>>>>>>
>>>>>>>>>>> We were monitoring our ds1 and ds2 physical backend to see
>>>>>>>>>>> performance
>>>>>>>>>>> and
>>>>>>>>>>> we suspect we've run out of IOPS since we're reaching the
>>>>>>>>>>> maximum
>>>>>>>>>>> specified
>>>>>>>>>>> by the manufacturer, probably at certain times the host
>>>>>>>>>>> cannot
>>>>>>>>>>> perform
>>>>>>>>>>> a
>>>>>>>>>>> storage operation within some time limit and it marks VMs as
>>>>>>>>>>> unresponsive.
>>>>>>>>>>> That's why we've set up ds3 and we're migrating ds1 and ds2
>>>>>>>>>>> to
>>>>>>>>>>> ds3.
>>>>>>>>>>> When
>>>>>>>>>>> we
>>>>>>>>>>> run out of space on ds3 we'll create more smaller volumes to
>>>>>>>>>>> keep
>>>>>>>>>>> migrating.
>>>>>>>>>>>
>>>>>>>>>>> On the host side, when this happens, we've run repoplot on
>>>>>>>>>>> the
>>>>>>>>>>> vdsm
>>>>>>>>>>> log
>>>>>>>>>>> and
>>>>>>>>>>> I'm attaching the result. Clearly there's a *huge* LVM
>>>>>>>>>>> response
>>>>>>>>>>> time
>>>>>>>>>>> (~30
>>>>>>>>>>> secs.).
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Indeed the log show very slow vgck and vgs commands - these
>>>>>>>>>> are
>>>>>>>>>> called
>>>>>>>>>> every
>>>>>>>>>> 5 minutes for checking the vg health and refreshing vdsm lvm
>>>>>>>>>> cache.
>>>>>>>>>>
>>>>>>>>>> 1. starting vgck
>>>>>>>>>>
>>>>>>>>>> Thread-96::DEBUG::2016-04-29
>>>>>>>>>> 13:17:48,682::lvm::290::Storage.Misc.excCmd::(cmd)
>>>>>>>>>> /usr/bin/taskset
>>>>>>>>>> --cpu-list 0-23 /usr/bin/sudo -n /usr/sbin/lvm vgck --config '
>>>>>>>>>> devices
>>>>>>>>>> { pre
>>>>>>>>>> ferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1
>>>>>>>>>> write_cache_state=0 disable_after_error_count=3 filter = [
>>>>>>>>>> '\''a|/dev/mapper/36000eb3a4f1acbc20000000000000043|'\
>>>>>>>>>> '', '\''r|.*|'\'' ] } global { locking_type=1
>>>>>>>>>> prioritise_write_locks=1 wait_for_locks=1 use_lvmetad=0 }
>>>>>>>>>> backup
>>>>>>>>>> {
>>>>>>>>>> retain_min = 50 retain_days = 0 } ' 5de4a000-a9c4-48
>>>>>>>>>> 9c-8eee-10368647c413 (cwd None)
>>>>>>>>>>
>>>>>>>>>> 2. vgck ends after 55 seconds
>>>>>>>>>>
>>>>>>>>>> Thread-96::DEBUG::2016-04-29
>>>>>>>>>> 13:18:43,173::lvm::290::Storage.Misc.excCmd::(cmd) SUCCESS:
>>>>>>>>>> <err> =
>>>>>>>>>> '
>>>>>>>>>> WARNING: lvmetad is running but disabled. Restart lvmetad
>>>>>>>>>> before
>>>>>>>>>> enabling it!\n'; <rc> = 0
>>>>>>>>>>
>>>>>>>>>> 3. starting vgs
>>>>>>>>>>
>>>>>>>>>> Thread-96::DEBUG::2016-04-29
>>>>>>>>>> 13:17:11,963::lvm::290::Storage.Misc.excCmd::(cmd)
>>>>>>>>>> /usr/bin/taskset
>>>>>>>>>> --cpu-list 0-23 /usr/bin/sudo -n /usr/sbin/lvm vgs --config '
>>>>>>>>>> devices
>>>>>>>>>> { pref
>>>>>>>>>> erred_names = ["^/dev/mapper/"] ignore_suspended_devices=1
>>>>>>>>>> write_cache_state=0 disable_after_error_count=3 filter = [
>>>>>>>>>> '\''a|/dev/mapper/36000eb3a4f1acbc20000000000000043|/de
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> v/mapper/36000eb3a4f1acbc200000000000000b9|/dev/mapper/360014056f0dc8930d744f83af8ddc709|/dev/mapper/WDC_WD5003ABYZ-011FA0_WD-WMAYP0J73DU6|'\'',
>>>>>>>>>> '\''r|.*|'\'' ] } global {
>>>>>>>>>> locking_type=1 prioritise_write_locks=1 wait_for_locks=1
>>>>>>>>>> use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 }
>>>>>>>>>> '
>>>>>>>>>> --noheadings --units b --nosuffix --separator '|
>>>>>>>>>> ' --ignoreskippedcluster -o
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name
>>>>>>>>>> 5de4a000-a9c4-489c-8eee-10368
>>>>>>>>>> 647c413 (cwd None)
>>>>>>>>>>
>>>>>>>>>> 4. vgs finished after 37 seconds
>>>>>>>>>>
>>>>>>>>>> Thread-96::DEBUG::2016-04-29
>>>>>>>>>> 13:17:48,680::lvm::290::Storage.Misc.excCmd::(cmd) SUCCESS:
>>>>>>>>>> <err> =
>>>>>>>>>> '
>>>>>>>>>> WARNING: lvmetad is running but disabled. Restart lvmetad
>>>>>>>>>> before
>>>>>>>>>> enabling it!\n'; <rc> = 0
>>>>>>>>>>
>>>>>>>>>> Zdenek, how do you suggest to debug this slow lvm commands?
>>>>>>>>>>
>>>>>>>>>> Can you run the following commands on a host in trouble, and
>>>>>>>>>> on
>>>>>>>>>> some
>>>>>>>>>> other
>>>>>>>>>> hosts in the same timeframe?
>>>>>>>>>>
>>>>>>>>>> time vgck -vvvv --config ' devices { filter =
>>>>>>>>>> ['\''a|/dev/mapper/36000eb3a4f1acbc20000000000000043|'\'',
>>>>>>>>>> '\''r|.*|'\'' ] } global { locking_type=1
>>>>>>>>>> prioritise_write_locks=1
>>>>>>>>>> wait_for_locks=1 use_lvmetad=0 } backup { retain_min = 50
>>>>>>>>>> retain_days = 0 } ' 5de4a000-a9c4-489c-8eee-10368647c413
>>>>>>>>>>
>>>>>>>>>> time vgs -vvvv --config ' global { locking_type=1
>>>>>>>>>> prioritise_write_locks=1 wait_for_locks=1 use_lvmetad=0 }
>>>>>>>>>> backup
>>>>>>>>>> {
>>>>>>>>>> retain_min = 50 retain_days = 0 } '
>>>>>>>>>> 5de4a000-a9c4-489c-8eee-10368647c413
>>>>>>>>>>
>>>>>>>>>> Note that I added -vvvv to both commands, this will generate
>>>>>>>>>> huge
>>>>>>>>>> amount
>>>>>>>>>> of debugging info. Please share the output of these commands.
>>>>>>>>>>
>>>>>>>>>> You may need to fix the commands. You can always copy and
>>>>>>>>>> paste
>>>>>>>>>> directly
>>>>>>>>>> from vdsm log into the shell and add the -vvvv flag.
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Indeed, there seems to be a big difference on hosts 5 and 6.
>>>>>>>>> I'm
>>>>>>>>> attaching
>>>>>>>>> the results of the execution of both commands on all hosts.
>>>>>>>>> Both
>>>>>>>>> commands
>>>>>>>>> show a pretty bigger output on hosts 5 and 6, and also a much
>>>>>>>>> bigger
>>>>>>>>> execution time. Times are also attached in a file called TIMES.
>>>>>>>>>
>>>>>>>>>>> Our host storage network is correctly configured and on a 1G
>>>>>>>>>>> interface, no errors on the host itself, switches, etc.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> 1G serving about 20-70 vms per host? (495 vms, 120 always up,
>>>>>>>>>> 7
>>>>>>>>>> hosts)?
>>>>>>>>>>
>>>>>>>>>> Do you have separate network for management and storage, or
>>>>>>>>>> both
>>>>>>>>>> use this 1G interface?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Yes, we have separate networks for management, storage and
>>>>>>>>> motion.
>>>>>>>>> Storage
>>>>>>>>> and motion have 1G each (plus, for storage we use a bond of 2
>>>>>>>>> interfaces
>>>>>>>>> in
>>>>>>>>> ALB-mode (6)). Currently no host has more than 30 VMs at a
>>>>>>>>> time.
>>>>>>>>>
>>>>>>>>>>> We've also limited storage in QoS to use 10MB/s and 40 IOPS,
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> How did you configure this limit?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> In the Data Center tab, I chose our DC and a QoS sub-tab
>>>>>>>>> appears,
>>>>>>>>> just
>>>>>>>>> like
>>>>>>>>> described here:
>>>>>>>>> http://www.ovirt.org/documentation/sla/network-qos/
>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>> but this issue
>>>>>>>>>>> still happens, which leads me to be concerned whether this is
>>>>>>>>>>> not
>>>>>>>>>>> just
>>>>>>>>>>> an
>>>>>>>>>>> IOPS issue; each host handles about cca. 600 LVs. Could this
>>>>>>>>>>> be an
>>>>>>>>>>> issue
>>>>>>>>>>> too? I remark the LVM response times are low in normal
>>>>>>>>>>> conditions
>>>>>>>>>>> (~1-2
>>>>>>>>>>> seconds).
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> We recommend to limit number lvs per vg to 350. If you have
>>>>>>>>>> 276
>>>>>>>>>> disks
>>>>>>>>>> on
>>>>>>>>>> ds1, and the disks are using snapshots, you may have too many
>>>>>>>>>> lvs,
>>>>>>>>>> which
>>>>>>>>>> can cause slowdowns in lvm operations.
>>>>>>>>>>
>>>>>>>>>> Can you share the output of:
>>>>>>>>>>
>>>>>>>>>> vdsm-tool dump-volume-chains
>>>>>>>>>> 5de4a000-a9c4-489c-8eee-10368647c413
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Ok, right now no VG has more than 350 VGs so I guess this is
>>>>>>>>> not
>>>>>>>>> currently
>>>>>>>>> the problem. Unfortunately, I run the vdsm-tool command but it
>>>>>>>>> didn't
>>>>>>>>> end
>>>>>>>>> nor provide any output in cca. 1 hour, so I guess it was hanged
>>>>>>>>> and
>>>>>>>>> I
>>>>>>>>> stopped it. If you confirm this is a normal execution time I
>>>>>>>>> can
>>>>>>>>> leave
>>>>>>>>> it
>>>>>>>>> running whatever time it takes.
>>>>>>>>>
>>>>>>>>> host5:~# vgs
>>>>>>>>> VG #PV #LV #SN Attr VSize
>>>>>>>>> VFree
>>>>>>>>> 0927c050-6fb6-463c-bb37-8b8da641dcd3 1 63 0 wz--n-
>>>>>>>>> 499,62g
>>>>>>>>> 206,50g
>>>>>>>>> 5de4a000-a9c4-489c-8eee-10368647c413 1 335 0 wz--n-
>>>>>>>>> 2,00t
>>>>>>>>> 518,62g
>>>>>>>>> b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8 1 215 0 wz--n-
>>>>>>>>> 2,00t
>>>>>>>>> 495,25g
>>>>>>>>> sys_vg 1 6 0 wz--n-
>>>>>>>>> 136,44g
>>>>>>>>> 122,94g
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> I'm attaching the vdsm.log, engine.log and repoplot PDF;
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> This is very useful, thanks. Can you send also the vdsm logs
>>>>>>>>>> and
>>>>>>>>>> repoplots
>>>>>>>>>> from other hosts for the same timeframe?
>>>>>>>>>>
>>>>>>>>>>> if someone could
>>>>>>>>>>> give a hint on some additional problems in them and shed some
>>>>>>>>>>> light
>>>>>>>>>>> on
>>>>>>>>>>> the
>>>>>>>>>>> above thoughts I'd be very grateful.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Do you have sar configured on the host? having sar logs can
>>>>>>>>>> reveal
>>>>>>>>>> more
>>>>>>>>>> info about this timeframe.
>>>>>>>>>>
>>>>>>>>>> Do you have information about amount of io from vms during
>>>>>>>>>> this
>>>>>>>>>> timeframe?
>>>>>>>>>> amount of io on the storage backend during this timeframe?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Not currently, but I'll be alert for the time this happens
>>>>>>>>> again and
>>>>>>>>> I'll
>>>>>>>>> check some sar commands related to I/O and I'll provide
>>>>>>>>> feedback.
>>>>>>>>> Nevertheless, by the time I run the commands above no machine
>>>>>>>>> was
>>>>>>>>> unresponsive and I'm still getting such huge execution times. I
>>>>>>>>> tried
>>>>>>>>> running iotop now and I see there are 2 vgck and vgs processes
>>>>>>>>> with
>>>>>>>>> a
>>>>>>>>> rate
>>>>>>>>> of ~500Kb/s each for reading.
>>>>>>>>>
>>>>>>>>> root 24446 1.3 0.0 57008 6824 ? D< 09:15
>>>>>>>>> 0:00
>>>>>>>>> /usr/sbin/lvm vgs --config devices { preferred_names =
>>>>>>>>> ["^/dev/mapper/"]
>>>>>>>>> ignore_suspended_devices=1 write_cache_state=0
>>>>>>>>> disable_after_error_count=3
>>>>>>>>> filter = [
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> 'a|/dev/mapper/36000eb3a4f1acbc20000000000000043|/dev/mapper/36000eb3a4f1acbc200000000000000b9|/dev/mapper/360014056f0dc8930d744f83af8ddc709|',
>>>>>>>>> 'r|.*|' ] } global { locking_type=1 prioritise_write_locks=1
>>>>>>>>> wait_for_locks=1 use_lvmetad=0 } backup { retain_min = 50
>>>>>>>>> retain_days
>>>>>>>>> = 0
>>>>>>>>> } --noheadings --units b --nosuffix --separator |
>>>>>>>>> --ignoreskippedcluster
>>>>>>>>> -o
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name
>>>>>>>>> b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d
>>>>>>>>>
>>>>>>>>> I'm also attaching the iostat output for host 5 in a file
>>>>>>>>> called
>>>>>>>>> iostat-host5.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> Interesting, all hosts are checking the same storage, but on
>>>>>>>> host5
>>>>>>>> and
>>>>>>>> host6
>>>>>>>> the output of vgs and vgck is 10 times bigger - this explain why
>>>>>>>> they
>>>>>>>> take
>>>>>>>> about
>>>>>>>> 10 times longer to run.
>>>>>>>>
>>>>>>>> $ ls -lh vgs-*
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 221K Apr 30 08:55 vgs-host1
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 239K Apr 30 08:55 vgs-host2
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 228K Apr 30 08:55 vgs-host3
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 288K Apr 30 08:55 vgs-host4
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 2.2M Apr 30 08:55 vgs-host5
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 2.2M Apr 30 08:55 vgs-host6
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 232K Apr 30 08:55 vgs-host7
>>>>>>>> $ ls -lh vgck-*
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 238K Apr 30 08:55 vgck-host1
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 254K Apr 30 08:55 vgck-host2
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 244K Apr 30 08:55 vgck-host3
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 298K Apr 30 08:55 vgck-host4
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 2.0M Apr 30 08:55 vgck-host5
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 2.0M Apr 30 08:55 vgck-host6
>>>>>>>> -rw-r--r--. 1 nsoffer nsoffer 248K Apr 30 08:55 vgck-host7
>>>>>>>>
>>>>>>>> Can you do collect the output of "dmsetup table -v" on host 1,
>>>>>>>> 5, and
>>>>>>>> 6?
>>>>>>>>
>>>>>>>> Nir
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Sure, please find attached results of the command. Once again,
>>>>>>> for
>>>>>>> hosts
>>>>>>> 5
>>>>>>> and 6 the size is 10 times bigger than for host 1.
>>>>>>
>>>>>>
>>>>>>
>>>>>> I think the issue causing slow vgs and vgck commands is stale
>>>>>> lvs on host 5 and 6. This may be the root caused for paused vms,
>>>>>> but I
>>>>>> cannot
>>>>>> explain how it is related yet.
>>>>>>
>>>>>> Comparing vgck on host1 and host5 - we can see that vgck opens
>>>>>> 213 /dev/mapper/* devices, actually 53 uniq devices, most of them
>>>>>> are opened 4 times. On host5, vgck opens 2489 devices (622 uniq).
>>>>>> This explains why the operation takes about 10 times longer.
>>>>>>
>>>>>> Checking dmsteup table output, we can see that host1 has 53
>>>>>> devices,
>>>>>> and host5 622 devices.
>>>>>>
>>>>>> Checking the device open count, host1 has 15 stale devices
>>>>>> (Open count: 0), but host5 has 597 stale devices.
>>>>>>
>>>>>> Leaving stale devices is a known issue, but we never had evidence
>>>>>> that
>>>>>> it
>>>>>> cause
>>>>>> trouble except warnings in lvm commands.
>>>>>>
>>>>>> Please open an ovirt bug about this issue, and include all the
>>>>>> files
>>>>>> you
>>>>>> sent
>>>>>> so far in this thread, and all the vdsm logs on host5.
>>>>>>
>>>>>> To remove the stale devices, you can do:
>>>>>>
>>>>>> for name in `dmsetup info -c -o open,name | awk '/ 0 / {print
>>>>>> $2}'`; do
>>>>>> echo "removing stale device: $name"
>>>>>> dmsetup remove $name
>>>>>> done
>>>>>
>>>>>
>>>>>
>>>>> Note that this cleanup is safe only in maintenance mode, since it
>>>>> will
>>>>> also remove
>>>>> the mapping for vdsm special lvs (ids, leases, inbox, outbox,
>>>>> master,
>>>>> metatada)
>>>>> that are accessed by vdsm regularly, and are not stale.
>>>>>
>>>>> This is also not safe if you use hosted engine, hosted engine agent
>>>>> should maintain
>>>>> its vg.
>>>>>
>>>>> The safest way to remove stale devices is to restart vdsm - it
>>>>> deactivates all unused
>>>>> lvs (except special lvs) during startup.
>>>>>
>>>>
>>>> Hm, I run it without even putting the host on maintenance, but I
>>>> will
>>>> next
>>>> time. Fortunately it seems it didn't do any harm and everything is
>>>> working.
>>>> I'll probably do a script that will put host on maintenance, cleanup
>>>> or
>>>> restart vdsm and start again (this is not a hosted engine) if the
>>>> number
>>>> of
>>>> stale devices is bigger than a threshold.
>>>
>>>
>>> I would not do anything automatic at this point except monitoring
>>> this
>>> issue.
>>>
>>> For cleanup - you have 2 options:
>>>
>>> - host is up - restart vdsm
>>> - host in maintenance - remove stale devices
>>>
>>> Based on local testing, I think the issue is this:
>>>
>>> - When connecting to storage, all lvs becomes active - this may be a
>>> change
>>> in lvm during el 7 development that we did not notice.
>>>
>>> - Each time vdsm is restarted, all active lvs that should not be
>>> active
>>> are
>>> deactivated during vdsm startup
>>>
>>> - When deactivating storage domain, vdsm does not deactivate the lvs
>>> leaving stale devices.
>>>
>>> Can you confirm that works like this on your system?
>>>
>>> To test this:
>>>
>>
>> I did these tests on host5. Before switching the host to maintenance,
>> I run
>> the vgck command and execution time was: 0m1.347s. Current stale
>> devices at
>> that time were:
>>
>> 5de4a000--a9c4--489c--8eee--10368647c413-master
>> 5de4a000--a9c4--489c--8eee--10368647c413-outbox
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-metadata
>> 5de4a000--a9c4--489c--8eee--10368647c413-ids
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-leases
>> 5de4a000--a9c4--489c--8eee--10368647c413-inbox
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-leases
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-metadata
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-ids
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-inbox
>> 5de4a000--a9c4--489c--8eee--10368647c413-leases
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-master
>> 5de4a000--a9c4--489c--8eee--10368647c413-metadata
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-master
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-outbox
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-inbox
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-outbox
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-ids
>>
>> (seems there were not any new stale devices since yesterday after
>> running
>> the loop).
>
> Expected
>
> - vdsm access master, metadata, inbox and outbox from time to time,
> they must
> be active when host is up
> - sanlock access ids when host is up - this lv should have open count
> of 1
>
>>
>>> 1. Put one host to maintenance
>>>
>>> You should see some stale devices - the special lvs
>>> (ids, leases, master, metadata, inbox, outbox)
>>>
>>> And probably 2 OVF_STORE lvs per vg (128m lvs used to store
>>> vm ovf)
>>>
>>
>> Still had the same devices as above.
>
> Expected bug - we don't cleanup lvs properly when entering maintenance.
>
>>
>>> 2. Cleanup the stale devices
>>>
>>
>> After cleaning the stale devices, those remained:
>>
>> 36000eb3a4f1acbc20000000000000043
>> 360014056f0dc8930d744f83af8ddc709
>> 36000eb3a4f1acbc200000000000000b9
>
> Expected bug.
>
> These are the multipath mappings, running multipath -F should remove
> them.
>
> If we clean the lvs properly when deactivating domain during
> maintenance, these
> mappings will be automatically removed.
>
>>> 3. Activate host
>>>
>>> You should see again about 600 stale devices, and lvm commands
>>> will probably run much slower as you reported.
>>>
>>
>> Current stale devices were these:
>>
>> 5de4a000--a9c4--489c--8eee--10368647c413-master
>> 5de4a000--a9c4--489c--8eee--10368647c413-outbox
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-metadata
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-leases
>> 5de4a000--a9c4--489c--8eee--10368647c413-inbox
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-leases
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-metadata
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-inbox
>> 5de4a000--a9c4--489c--8eee--10368647c413-leases
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-master
>> 5de4a000--a9c4--489c--8eee--10368647c413-metadata
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-master
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-outbox
>> b13b9eac--1f2e--4a7e--bcd9--49f5f855c3d8-outbox
>> 0927c050--6fb6--463c--bb37--8b8da641dcd3-inbox
>
> Strange, on my test setup (RHEL 7.2), *all* the lvs in the vg get
> activated.
>
> Did you check the output of lvs?
>
> pvscan --cache
> lvs
>
> I guess you will see about 600 lvs active (-wi-a-----)
>
> Maybe you did not wait until host connected to all storage domains?
>
Ok, that was the problem, I didn't run the 'pvscan --cache' command
prior to see the output. After activating the host again, I see 620 LVs.
However, in my case all LVs except the special ones are inactive:
host5:~# lvscan | grep -v inactive
ACTIVE '/dev/0927c050-6fb6-463c-bb37-8b8da641dcd3/metadata'
[512,00 MiB] inherit
ACTIVE '/dev/0927c050-6fb6-463c-bb37-8b8da641dcd3/outbox'
[128,00 MiB] inherit
ACTIVE '/dev/0927c050-6fb6-463c-bb37-8b8da641dcd3/leases'
[2,00 GiB] inherit
ACTIVE '/dev/0927c050-6fb6-463c-bb37-8b8da641dcd3/ids'
[128,00 MiB] inherit
ACTIVE '/dev/0927c050-6fb6-463c-bb37-8b8da641dcd3/inbox'
[128,00 MiB] inherit
ACTIVE '/dev/0927c050-6fb6-463c-bb37-8b8da641dcd3/master'
[1,00 GiB] inherit
ACTIVE '/dev/sys_vg/audit' [512,00 MiB] inherit
ACTIVE '/dev/sys_vg/tmp' [1,00 GiB] inherit
ACTIVE '/dev/sys_vg/var' [4,00 GiB] inherit
ACTIVE '/dev/sys_vg/home' [1,00 GiB] inherit
ACTIVE '/dev/sys_vg/root' [6,00 GiB] inherit
ACTIVE '/dev/sys_vg/swap' [1,00 GiB] inherit
ACTIVE '/dev/5de4a000-a9c4-489c-8eee-10368647c413/metadata'
[512,00 MiB] inherit
ACTIVE '/dev/5de4a000-a9c4-489c-8eee-10368647c413/outbox'
[128,00 MiB] inherit
ACTIVE '/dev/5de4a000-a9c4-489c-8eee-10368647c413/leases'
[2,00 GiB] inherit
ACTIVE '/dev/5de4a000-a9c4-489c-8eee-10368647c413/ids'
[128,00 MiB] inherit
ACTIVE '/dev/5de4a000-a9c4-489c-8eee-10368647c413/inbox'
[128,00 MiB] inherit
ACTIVE '/dev/5de4a000-a9c4-489c-8eee-10368647c413/master'
[1,00 GiB] inherit
ACTIVE '/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/metadata'
[512,00 MiB] inherit
ACTIVE '/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/outbox'
[128,00 MiB] inherit
ACTIVE '/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/leases'
[2,00 GiB] inherit
ACTIVE '/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/ids'
[128,00 MiB] inherit
ACTIVE '/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/inbox'
[128,00 MiB] inherit
ACTIVE '/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/master'
[1,00 GiB] inherit
Others are all 'inactive':
inactive
'/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/d256c965-25dd-40f2-aeae-4a3ae10befcf'
[3,12 GiB] inherit
inactive
'/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/6cfafa3a-c335-47bf-805e-bddb850dc914'
[3,12 GiB] inherit
inactive
'/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/0d60a745-6952-42e7-8bcf-a12d36b2c39e'
[5,25 GiB] inherit
inactive
'/dev/b13b9eac-1f2e-4a7e-bcd9-49f5f855c3d8/38d94545-b4b0-4384-ae3a-fa26c40e40e3'
[5,25 GiB] inherit
I tested this on both hosts (5 and 6) with same result.
>>> 4. Restart vdsm
>>>
>>> All the regular lvs should be inactive now, no stale devices
>>> should exists, except the special lvs (expected)
>>>
>>
>> Same result as above. The strange thing is that now I don't see any
>> VGs
>> running the 'vgs' command but the system's:
>>
>> host5:~# vgs
>> VG #PV #LV #SN Attr VSize VFree
>> sys_vg 1 6 0 wz--n- 136,44g 122,94g
>
> Vdsm bypass lvmetads, so all lvm commands from the shell show incorrect
> results. You must update lvmetad about changes made by vdsm using
>
> pvscan --cache
> vgs
>
> Or using vdsm way:
>
> vgs --config 'global {use_lvmetad=0}'
>
(Same here, after using 'pvscan --cache' I can see the VGs).
>> However, machines running on that host have no issues and storage is
>> working
>> well. vgscan doesn't do the trick either. I tested this on host6 too
>> and the
>> same happens: After reactivating host I cannot see VGs with the vgs
>> command
>> - however, everything seems to work quite well.
>>
>> This is CentOS Linux release 7.2.1511 FWIW.
>
> Nir
More information about the Users
mailing list