Slow reboots due to ZFS cleanup in kern_shutdown() .. zio_fini()

[Peter Eriksson]

… and X levels deeper it gives this (not all filesystems mounted - I rebooted fairly quickly):

keg_drain: while (SLIST_FIRST/SLIST_REMOVE)-loop took 14 seconds [20021 loops]
zone_drain_wait(): zone_foreach_keg(zone, &keg_drain) took 14 seconds
zone_dtor(): zone_drain_wait(zone, M_WAITOK) took 14 seconds
zone_free_item(zone=UMA Zones): zone->uz_dtor() took 14 seconds
uma_zdestroy(zio_buf_12288) took 14 seconds
kmem_cache_destroy: uma_zdestroy(0xfffff803467c8ac0) [zio_buf_12288] took 14 seconds
kmem_cache_destroy(zio_buf_cache[20]) took 14 seconds


Hmm… I wonder if it isn’t this code I /usr/src/sys/sys/queue.h:

> #define SLIST_REMOVE(head, elm, type, field) do {                       \
>        QMD_SAVELINK(oldnext, (elm)->field.sle_next);                   \
>        if (SLIST_FIRST((head)) == (elm)) {                             \
>                SLIST_REMOVE_HEAD((head), field);                       \
>        }                                                               \
>        else {                                                          \
>                QUEUE_TYPEOF(type) *curelm = SLIST_FIRST(head);         \
>                while (SLIST_NEXT(curelm, field) != (elm))              \
>                        curelm = SLIST_NEXT(curelm, field);             \
>                SLIST_REMOVE_AFTER(curelm, field);                      \
>        }                                                               \
>        TRASHIT(*oldnext);                                              \
> } while (0)

Combined with this in /usr/src/sys/vm/uma_core.c: keg_drain():

> finished:
>        KEG_UNLOCK(keg);
>
>        while ((slab = SLIST_FIRST(&freeslabs)) != NULL) {
>                SLIST_REMOVE(&freeslabs, slab, uma_slab, us_hlink);
>                keg_free_slab(keg, slab, keg->uk_ipers);
>        }

(The keg_drain print above is the time for the while() loop).

If I’m reading this right it looks like it’s potentially doing a linear search through a (long) linked list, for every entry in the free slabs list. 20000 entries in 14 seconds is 1400 entries per second.

Hmmm… It feels like this code could be optimised at bit.

- Peter


> On 3 Dec 2019, at 18:31, Peter Eriksson <pen at lysator.liu.se> wrote:
> 
> zio_fini: kmem_cache_destroy(zio_buf_cache & zio_data_buf_cache):
> 
> zone_free_item(zone=UMA Zones): zone->uz_dtor() took 16 seconds
> uma_zdestroy(zio_buf_12288) took 16 seconds
> kmem_cache_destroy: uma_zdestroy(0xfffff8034678e980) [zio_buf_12288] took 16 seconds
> kmem_cache_destroy(zio_buf_cache[20]) took 16 seconds
> 
> zone_free_item(zone=UMA Zones): zone->uz_dtor() took 60 seconds
> uma_zdestroy(zio_buf_16384) took 60 seconds
> kmem_cache_destroy: uma_zdestroy(0xfffff8034678e880) [zio_buf_16384] took 60 seconds
> kmem_cache_destroy(zio_buf_cache[28]) took 60 seconds
> 
> 
> Looks like it is the call to zone->uz_dtor that is taking time (added time check around the various parts of zone_free_item().
> 
> - Peter
> 
>> Indeed, looking at the vmstat -z output this doesn't really make sense.
>> It would be useful to confirm that we are in fact spending most of the
>> time reclaiming items.
> 
> _______________________________________________
> freebsd-fs at freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-fs
> To unsubscribe, send any mail to "freebsd-fs-unsubscribe at freebsd.org"