From owner-freebsd-fs@freebsd.org Tue Dec 3 16:22:24 2019 Return-Path: Delivered-To: freebsd-fs@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id C1C821B45BA for ; Tue, 3 Dec 2019 16:22:24 +0000 (UTC) (envelope-from markjdb@gmail.com) Received: from mail-qt1-x843.google.com (mail-qt1-x843.google.com [IPv6:2607:f8b0:4864:20::843]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) server-signature RSA-PSS (4096 bits) client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1O1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 47S6hJ4l7Mz4ZFL; Tue, 3 Dec 2019 16:22:24 +0000 (UTC) (envelope-from markjdb@gmail.com) Received: by mail-qt1-x843.google.com with SMTP id s8so1125260qte.2; Tue, 03 Dec 2019 08:22:24 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=sender:date:from:to:cc:subject:message-id:references:mime-version :content-disposition:content-transfer-encoding:in-reply-to :user-agent; bh=fhnwZruAW+hV89B1Oe4xe+b1SQSnVof2N96jwNOigJ8=; b=rr3933G5ZB8A7IMwlvKTtxUsyvXxyCBHLq4BVFLR2dV41bbUFugvTjTyyMleibpP4a y4mOCWexf1uv7VuXjcp5U0XqIgSI9qPQeZ6k+AMiPbRdPry0n35wHq8EAGgiwG7zFwTU 4PBor1/qqMsUYu3Y8wQqeIoNAlYacRsEYW9Hak/8CW8iUAO0iSEBSouWf87Kxcmf9ALU PK/k75xgRuRnk8nUKtNnWtyzZGqPStvc0qB+C1zNwxoCmd4f1fDE3/Z6QoinnLnP9njN 4A+5FWFe4OXM5+EGEgVACsEurEyxVTdNq0UylipeA2J+t9sWXrfMhIbgvdlJTOz5ILkX xe4A== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:sender:date:from:to:cc:subject:message-id :references:mime-version:content-disposition :content-transfer-encoding:in-reply-to:user-agent; bh=fhnwZruAW+hV89B1Oe4xe+b1SQSnVof2N96jwNOigJ8=; b=hTBrRISIpnslGbKAXdJGPON5tGep4Knkdw8kvkdfeGBGnRlegiWeCL/J3hebfHfenJ cJcbH+dES0oIU1bcscG9pkzkHK8IDbGNhQcu4YT+VfDvHCl84rkvUS6YM1M8jjGeQonN CktrRLYlUy1VuLFheZTK1WadIkcchbQPUM5sugxPghEljUBFy4MK3bqqrdd1CAabhizd b8I2kYOrvRLxSOnwR1BVme+VH1w8a32x7b4r9JWwktEJS6wLVvCaC+KaJUqNxca4yDi+ 4M9z0Q1ZpW8Al3aTlGJqCuYw7PVEL6zCy66Gxr6x6NdAO01ZGUZZgTfOWkZX0uRltAKw KddQ== X-Gm-Message-State: APjAAAV4zcfMaGT77SxzmbLp682mAEsX6As83jhUKUSBg+B/PTBA6oR+ Kp/6qx1dAjvXB5g4a1q8br4r34eLLzc= X-Google-Smtp-Source: APXvYqzUWJWybkoCBPzhH0yum8OiM1dEubYFPg3CmvpNBw+UhVzhwAjwLbYS8m+Tla8wImXprozoOA== X-Received: by 2002:ac8:3946:: with SMTP id t6mr5864326qtb.278.1575390142260; Tue, 03 Dec 2019 08:22:22 -0800 (PST) Received: from raichu (toroon0560w-lp130-05-69-158-183-252.dsl.bell.ca. [69.158.183.252]) by smtp.gmail.com with ESMTPSA id u12sm2054577qta.79.2019.12.03.08.22.21 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 03 Dec 2019 08:22:21 -0800 (PST) Sender: Mark Johnston Date: Tue, 3 Dec 2019 11:22:19 -0500 From: Mark Johnston To: Andriy Gapon Cc: Peter Eriksson , freebsd-fs@freebsd.org Subject: Re: Slow reboots due to ZFS cleanup in kern_shutdown() .. zio_fini() Message-ID: <20191203162219.GI43802@raichu> References: <20191202225424.GG43802@raichu> <3b71fe37-c29f-e3e5-ff96-5dce15cc7553@FreeBSD.org> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: <3b71fe37-c29f-e3e5-ff96-5dce15cc7553@FreeBSD.org> User-Agent: Mutt/1.12.2 (2019-09-21) X-Rspamd-Queue-Id: 47S6hJ4l7Mz4ZFL X-Spamd-Bar: ----- Authentication-Results: mx1.freebsd.org; none X-Spamd-Result: default: False [-6.00 / 15.00]; NEURAL_HAM_MEDIUM(-1.00)[-0.996,0]; REPLY(-4.00)[]; NEURAL_HAM_LONG(-1.00)[-0.999,0] X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 03 Dec 2019 16:22:24 -0000 On Tue, Dec 03, 2019 at 11:03:11AM +0200, Andriy Gapon wrote: > On 03/12/2019 00:54, Mark Johnston wrote: > > On Mon, Dec 02, 2019 at 11:39:01PM +0100, Peter Eriksson wrote: > >> 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… :-). > > > > uma_destroy() frees all of the memory cached in the zone back to the > > page allocator. This operation takes time proportional to the number of > > cached items. I would expect most of the time to be spent in > > zone_reclaim(), called by zone_dtor(). > > But spending *minutes* there is really unexpected. > I have never seen anything like that. > I wonder if there is anything untypical about the system's hardware (like a very > big number of processors) or configuration. 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.