From owner-freebsd-fs@freebsd.org Wed Dec 4 09:48:32 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 441E01CF410 for ; Wed, 4 Dec 2019 09:48:32 +0000 (UTC) (envelope-from agapon@gmail.com) Received: from mail-lj1-f170.google.com (mail-lj1-f170.google.com [209.85.208.170]) (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 47SYvM1wNwz4f0s for ; Wed, 4 Dec 2019 09:48:31 +0000 (UTC) (envelope-from agapon@gmail.com) Received: by mail-lj1-f170.google.com with SMTP id j6so7344112lja.2 for ; Wed, 04 Dec 2019 01:48:31 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:subject:to:references:from:openpgp:autocrypt :message-id:date:user-agent:mime-version:in-reply-to :content-language:content-transfer-encoding; bh=pB/zAWZTSgoeeyV0AaGHYdDBdi0bWMiwwMr2wAGCAk4=; b=CRuX9EuBALqO/VblvJu/i2+6wYgaFETqlwn9NExsKs+m8tdK6LVg4E4jgm/pHQH2Ef iG0sfFEiT1VzqFiHTKPD8vvX5dH3c2I0KB6d1JgpILY5e+7zDHjv+ZxBdijh1egMtq4T Svv1xeSgWWWFRuW4GfZEWCQ+aNAU+eisslgRrx2/F0/oTL3hvUS0COiU6fqm6/87Ob8x 4VwITOnRq5tP1aZ+PpuEWR3amVEZmMpHUVqL26+CkHO/TFv62JtWIVmINtQxNxbxoMHk js59YyfbknWjO7B8WNWegg0P7J+YZa1hRZccHu9nR6etYEVJPwXYlLnQBIDmCdFD5ueC qO2Q== X-Gm-Message-State: APjAAAWrggIHyh8yG5hpW+qmMXcPBZtwcuUAsSKFa2DZRr6XOxwwlaQZ y/l1KG/yT1u1akWiD5O8QuAqDqhNY0g= X-Google-Smtp-Source: APXvYqwvBECiCFHl+Tgizy9xP9nja/04hJFLJMX4GVVRcXtWMCBexIXvQVFee+I+qTvRUk1X5I5/PQ== X-Received: by 2002:a2e:9855:: with SMTP id e21mr1379063ljj.170.1575452909195; Wed, 04 Dec 2019 01:48:29 -0800 (PST) Received: from [192.168.0.88] (east.meadow.volia.net. [93.72.151.96]) by smtp.googlemail.com with ESMTPSA id n19sm2909290lfl.85.2019.12.04.01.48.27 (version=TLS1_3 cipher=TLS_AES_128_GCM_SHA256 bits=128/128); Wed, 04 Dec 2019 01:48:28 -0800 (PST) Subject: Re: Slow reboots due to ZFS cleanup in kern_shutdown() .. zio_fini() To: Peter Eriksson , FreeBSD FS References: <20191202225424.GG43802@raichu> <3b71fe37-c29f-e3e5-ff96-5dce15cc7553@FreeBSD.org> <20191203162219.GI43802@raichu> <247C6990-BC6E-4E3D-8CEF-5A861D8A25EC@lysator.liu.se> <4D44B25E-2F15-4536-A653-DA242051C8A9@lysator.liu.se> From: Andriy Gapon Openpgp: preference=signencrypt Autocrypt: addr=avg@FreeBSD.org; prefer-encrypt=mutual; keydata= mQINBFm4LIgBEADNB/3lT7f15UKeQ52xCFQx/GqHkSxEdVyLFZTmY3KyNPQGBtyvVyBfprJ7 mAeXZWfhat6cKNRAGZcL5EmewdQuUfQfBdYmKjbw3a9GFDsDNuhDA2QwFt8BmkiVMRYyvI7l N0eVzszWCUgdc3qqM6qqcgBaqsVmJluwpvwp4ZBXmch5BgDDDb1MPO8AZ2QZfIQmplkj8Y6Z AiNMknkmgaekIINSJX8IzRzKD5WwMsin70psE8dpL/iBsA2cpJGzWMObVTtCxeDKlBCNqM1i gTXta1ukdUT7JgLEFZk9ceYQQMJJtUwzWu1UHfZn0Fs29HTqawfWPSZVbulbrnu5q55R4PlQ /xURkWQUTyDpqUvb4JK371zhepXiXDwrrpnyyZABm3SFLkk2bHlheeKU6Yql4pcmSVym1AS4 dV8y0oHAfdlSCF6tpOPf2+K9nW1CFA8b/tw4oJBTtfZ1kxXOMdyZU5fiG7xb1qDgpQKgHUX8 7Rd2T1UVLVeuhYlXNw2F+a2ucY+cMoqz3LtpksUiBppJhw099gEXehcN2JbUZ2TueJdt1FdS ztnZmsHUXLxrRBtGwqnFL7GSd6snpGIKuuL305iaOGODbb9c7ne1JqBbkw1wh8ci6vvwGlzx rexzimRaBzJxlkjNfMx8WpCvYebGMydNoeEtkWldtjTNVsUAtQARAQABtB5BbmRyaXkgR2Fw b24gPGF2Z0BGcmVlQlNELm9yZz6JAlQEEwEIAD4WIQS+LEO7ngQnXA4Bjr538m7TUc1yjwUC WbgsiAIbIwUJBaOagAULCQgHAgYVCAkKCwIEFgIDAQIeAQIXgAAKCRB38m7TUc1yj+JAEACV l9AK/nOWAt/9cufV2fRj0hdOqB1aCshtSrwHk/exXsDa4/FkmegxXQGY+3GWX3deIyesbVRL rYdtdK0dqJyT1SBqXK1h3/at9rxr9GQA6KWOxTjUFURsU7ok/6SIlm8uLRPNKO+yq0GDjgaO LzN+xykuBA0FlhQAXJnpZLcVfPJdWv7sSHGedL5ln8P8rxR+XnmsA5TUaaPcbhTB+mG+iKFj GghASDSfGqLWFPBlX/fpXikBDZ1gvOr8nyMY9nXhgfXpq3B6QCRYKPy58ChrZ5weeJZ29b7/ QdEO8NFNWHjSD9meiLdWQaqo9Y7uUxN3wySc/YUZxtS0bhAd8zJdNPsJYG8sXgKjeBQMVGuT eCAJFEYJqbwWvIXMfVWop4+O4xB+z2YE3jAbG/9tB/GSnQdVSj3G8MS80iLS58frnt+RSEw/ psahrfh0dh6SFHttE049xYiC+cM8J27Aaf0i9RflyITq57NuJm+AHJoU9SQUkIF0nc6lfA+o JRiyRlHZHKoRQkIg4aiKaZSWjQYRl5Txl0IZUP1dSWMX4s3XTMurC/pnja45dge/4ESOtJ9R 8XuIWg45Oq6MeIWdjKddGhRj3OohsltKgkEU3eLKYtB6qRTQypHHUawCXz88uYt5e3w4V16H lCpSTZV/EVHnNe45FVBlvK7k7HFfDDkryLkCDQRZuCyIARAAlq0slcsVboY/+IUJdcbEiJRW be9HKVz4SUchq0z9MZPX/0dcnvz/gkyYA+OuM78dNS7Mbby5dTvOqfpLJfCuhaNYOhlE0wY+ 1T6Tf1f4c/uA3U/YiadukQ3+6TJuYGAdRZD5EqYFIkreARTVWg87N9g0fT9BEqLw9lJtEGDY EWUE7L++B8o4uu3LQFEYxcrb4K/WKmgtmFcm77s0IKDrfcX4doV92QTIpLiRxcOmCC/OCYuO jB1oaaqXQzZrCutXRK0L5XN1Y1PYjIrEzHMIXmCDlLYnpFkK+itlXwlE2ZQxkfMruCWdQXye syl2fynAe8hvp7Mms9qU2r2K9EcJiR5N1t1C2/kTKNUhcRv7Yd/vwusK7BqJbhlng5ZgRx0m WxdntU/JLEntz3QBsBsWM9Y9wf2V4tLv6/DuDBta781RsCB/UrU2zNuOEkSixlUiHxw1dccI 6CVlaWkkJBxmHX22GdDFrcjvwMNIbbyfQLuBq6IOh8nvu9vuItup7qemDG3Ms6TVwA7BD3j+ 3fGprtyW8Fd/RR2bW2+LWkMrqHffAr6Y6V3h5kd2G9Q8ZWpEJk+LG6Mk3fhZhmCnHhDu6CwN MeUvxXDVO+fqc3JjFm5OxhmfVeJKrbCEUJyM8ESWLoNHLqjywdZga4Q7P12g8DUQ1mRxYg/L HgZY3zfKOqcAEQEAAYkCPAQYAQgAJhYhBL4sQ7ueBCdcDgGOvnfybtNRzXKPBQJZuCyIAhsM BQkFo5qAAAoJEHfybtNRzXKPBVwQAKfFy9P7N3OsLDMB56A4Kf+ZT+d5cIx0Yiaf4n6w7m3i ImHHHk9FIetI4Xe54a2IXh4Bq5UkAGY0667eIs+Z1Ea6I2i27Sdo7DxGwq09Qnm/Y65ADvXs 3aBvokCcm7FsM1wky395m8xUos1681oV5oxgqeRI8/76qy0hD9WR65UW+HQgZRIcIjSel9vR XDaD2HLGPTTGr7u4v00UeTMs6qvPsa2PJagogrKY8RXdFtXvweQFz78NbXhluwix2Tb9ETPk LIpDrtzV73CaE2aqBG/KrboXT2C67BgFtnk7T7Y7iKq4/XvEdDWscz2wws91BOXuMMd4c/c4 OmGW9m3RBLufFrOag1q5yUS9QbFfyqL6dftJP3Zq/xe+mr7sbWbhPVCQFrH3r26mpmy841ym dwQnNcsbIGiBASBSKksOvIDYKa2Wy8htPmWFTEOPRpFXdGQ27awcjjnB42nngyCK5ukZDHi6 w0qK5DNQQCkiweevCIC6wc3p67jl1EMFY5+z+zdTPb3h7LeVnGqW0qBQl99vVFgzLxchKcl0 R/paSFgwqXCZhAKMuUHncJuynDOP7z5LirUeFI8qsBAJi1rXpQoLJTVcW72swZ42IdPiboqx NbTMiNOiE36GqMcTPfKylCbF45JNX4nF9ElM0E+Y8gi4cizJYBRr2FBJgay0b9Cp Message-ID: Date: Wed, 4 Dec 2019 11:48:26 +0200 User-Agent: Mozilla/5.0 (X11; FreeBSD amd64; rv:60.0) Gecko/20100101 Thunderbird/60.8.0 MIME-Version: 1.0 In-Reply-To: <4D44B25E-2F15-4536-A653-DA242051C8A9@lysator.liu.se> Content-Type: text/plain; charset=utf-8 Content-Language: en-US Content-Transfer-Encoding: 8bit X-Rspamd-Queue-Id: 47SYvM1wNwz4f0s X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=none; spf=pass (mx1.freebsd.org: domain of agapon@gmail.com designates 209.85.208.170 as permitted sender) smtp.mailfrom=agapon@gmail.com X-Spamd-Result: default: False [-3.11 / 15.00]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; RCVD_TLS_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; R_SPF_ALLOW(-0.20)[+ip4:209.85.128.0/17]; NEURAL_HAM_LONG(-1.00)[-1.000,0]; MIME_GOOD(-0.10)[text/plain]; PREVIOUSLY_DELIVERED(0.00)[freebsd-fs@freebsd.org]; DMARC_NA(0.00)[FreeBSD.org]; NEURAL_HAM_MEDIUM(-1.00)[-1.000,0]; RCVD_COUNT_THREE(0.00)[3]; MIME_TRACE(0.00)[0:+]; TO_DN_ALL(0.00)[]; RCPT_COUNT_TWO(0.00)[2]; RCVD_IN_DNSWL_NONE(0.00)[170.208.85.209.list.dnswl.org : 127.0.5.0]; TO_MATCH_ENVRCPT_SOME(0.00)[]; IP_SCORE(-1.11)[ip: (-0.42), ipnet: 209.85.128.0/17(-3.15), asn: 15169(-1.93), country: US(-0.05)]; FORGED_SENDER(0.30)[avg@FreeBSD.org,agapon@gmail.com]; RWL_MAILSPIKE_POSSIBLE(0.00)[170.208.85.209.rep.mailspike.net : 127.0.0.17]; R_DKIM_NA(0.00)[]; FREEMAIL_ENVFROM(0.00)[gmail.com]; ASN(0.00)[asn:15169, ipnet:209.85.128.0/17, country:US]; FROM_NEQ_ENVFROM(0.00)[avg@FreeBSD.org,agapon@gmail.com]; MID_RHS_MATCH_FROM(0.00)[]; RECEIVED_SPAMHAUS_PBL(0.00)[96.151.72.93.khpj7ygk5idzvmvt5x4ziurxhy.zen.dq.spamhaus.net : 127.0.0.10] 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: Wed, 04 Dec 2019 09:48:32 -0000 On 04/12/2019 00:28, Peter Eriksson wrote: > … 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. It's not a search. The loop is removing *all* items. There is no other way to do it :-) Expanding your calculations, it takes on the order of a millisecond to process a single slab. I bet that the time is spent in keg_free_slab() and it's a lot of time. I wonder if the OR should actually be AND in this condition: if (!uma_dbg_kskip(keg, slab->us_data + (keg->uk_rsize * i)) || keg->uk_fini != trash_fini) Looks like there is a "ton" of memory reading done here. -- Andriy Gapon