Date: Mon, 2 Dec 2019 23:39:01 +0100 From: Peter Eriksson <pen@lysator.liu.se> To: =?utf-8?Q?Karli_Sj=C3=B6berg_via_freebsd-fs?= <freebsd-fs@freebsd.org> Subject: Re: Slow reboots due to ZFS cleanup in kern_shutdown() .. zio_fini() Message-ID: <D2A11CE9-9B24-4E40-A51A-8D318E0288C9@lysator.liu.se> In-Reply-To: <AD17E454-6A51-436D-A853-07F04A406EC9@lysator.liu.se> References: <AD17E454-6A51-436D-A853-07F04A406EC9@lysator.liu.se>
next in thread | previous in thread | raw e-mail | index | archive | help
Sigh. Slight correction, the output below should have said uma_zdestroy() and not uma_zfree_arg() (wrong printf text, but the right times). After an uptime of 7 hours, a reboot have these times (I removed the “uma” printf in this run): kmem_cache_destroy(zio_data_buf_cache[8]) took 2 seconds kmem_cache_destroy(zio_buf_cache[10]) took 6 seconds kmem_cache_destroy(zio_buf_cache[14]) took 2 seconds kmem_cache_destroy(zio_buf_cache[16]) took 136 seconds kmem_cache_destroy(zio_buf_cache[20]) took 31 seconds kmem_cache_destroy(zio_buf_cache[28]) took 303 seconds kmem_cache_destroy(zio_buf_cache[224]) took 89 seconds kmem_cache_destroy(zio_data_buf_cache[224]) took 31 seconds This is on a mostly idle server (well, apart from compiling the kernel code :-) and some snapshots being taken of all filesystems (once per hour). So now on to finding out why uma_destroy() is taking so long… :-). - Peter > On 2 Dec 2019, at 15:32, Peter Eriksson <pen@lysator.liu.se> wrote: > > I’ve been looking at trying to figure out why our servers take so long to reboot, where the most time is spent doing a “shutdown”. We’ve seen examples where it has taken 10-20 minutes (or more). > > This is Dell PowerEdge R730xd servers with 256GB RAM and ~140TB of disks. FreeBSD 11.3. With ~24000 filsystems per server. > We normally cap ARC to 128GB RAM. > > Adding a lot of debugging printf() calls to relevant parts of the code points to: > > kern_shutdown() -> > EVENTHANDLER_INVOKE(shutdown_post_sync) -> > zfsshutdown() -> > zfs__fini() -> > spa_fini() -> > zio_fini(): > > Debug output from a test run: > zio_fini: kmem_cache_destroy(zio_buf_cache & zio_data_buf_cache): > > kmem_cache_destroy: uma_zfree_arg(0xfffff803465eec00) [zio_buf_12288] took 16 seconds > kmem_cache_destroy(zio_buf_cache[20]) took 16 seconds > > kmem_cache_destroy: uma_zfree_arg(0xfffff803465eeb00) [zio_buf_16384] took 61 seconds > kmem_cache_destroy(zio_buf_cache[28]) took 61 seconds > > kmem_cache_destroy: uma_zfree_arg(0xfffff8034c9018c0) [zio_buf_131072] took 87 seconds > kmem_cache_destroy(zio_buf_cache[224]) took 87 seconds > > kmem_cache_destroy: uma_zfree_arg(0xfffff8034c901880) [zio_data_buf_131072] took 5 seconds > kmem_cache_destroy(zio_data_buf_cache[224]) took 5 seconds > > (I modified the code here to print the time spent if it took 2 seconds or more) > > This is on a newly rebooted server (with all filesystems mounted). Seems like uma_zfree_arg() is taking really long to execute. Now that code isn’t exactly easy to read (for me atleast)… Lot’s of barrier/locks and stuff. > > I wonder why this code should take so long? There shouldn’t be any disk I/O involved and it’s just a cache so I wonder if there might be some way to get rid of it quicker? Any UMA experts online? :-) > > Reason for this is that I’d like to be able to make sure a server reboots more quickly in case of problems. Now with the parallell ZFS mount stuff being done at boot time that part is much quicker :-). > > - Peter > > _______________________________________________ > freebsd-fs@freebsd.org mailing list > https://lists.freebsd.org/mailman/listinfo/freebsd-fs > To unsubscribe, send any mail to "freebsd-fs-unsubscribe@freebsd.org"
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?D2A11CE9-9B24-4E40-A51A-8D318E0288C9>