From nobody Tue Oct 31 14:38:04 2023 X-Original-To: freebsd-fs@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4SKXmv2cwdz4yS4D for ; Tue, 31 Oct 2023 14:38:07 +0000 (UTC) (envelope-from mjguzik@gmail.com) Received: from mail-oo1-xc2a.google.com (mail-oo1-xc2a.google.com [IPv6:2607:f8b0:4864:20::c2a]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1D4" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4SKXmt4tdhz3QXV for ; Tue, 31 Oct 2023 14:38:06 +0000 (UTC) (envelope-from mjguzik@gmail.com) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20230601 header.b=nEULfTpH; spf=pass (mx1.freebsd.org: domain of mjguzik@gmail.com designates 2607:f8b0:4864:20::c2a as permitted sender) smtp.mailfrom=mjguzik@gmail.com; dmarc=pass (policy=none) header.from=gmail.com Received: by mail-oo1-xc2a.google.com with SMTP id 006d021491bc7-5872c6529e1so393144eaf.0 for ; Tue, 31 Oct 2023 07:38:06 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1698763085; x=1699367885; darn=freebsd.org; h=cc:to:subject:message-id:date:from:references:in-reply-to :mime-version:from:to:cc:subject:date:message-id:reply-to; bh=yuIgZ8eGI9LCVHt6uMDHDxnUY2ZjrbScT/lrp36/mSc=; b=nEULfTpHFVNjepePtkQvE7I8k7VnhdhAowYKYJJHwiRpOSqbDVr9orINAPVhRucbD7 OJQWIluTFrka9ugrpSB9qwcVIBmac4R5vY1TosfahGRF4KipPc5O6sIRBICRz0+GZZdF H1LHD471qSR9HacWH+LwJWgj6lSsbDvVhNINps6sY3dFz4c4MkSp5ChA77cn0rHFO599 ndphPqSYR5JQCPdlb89E12LZt41Qh8hg5iHV93WuXRw6hUdpm3rLhIJptZMcb3FDZK2N 3ziZqLagonDIcTWY2fyyBhTT/0IP/qkUhijlBqJK3WOul+PSagXsI3JKOx8XvCQ/p/sn xQGQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1698763085; x=1699367885; h=cc:to:subject:message-id:date:from:references:in-reply-to :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=yuIgZ8eGI9LCVHt6uMDHDxnUY2ZjrbScT/lrp36/mSc=; b=NZSaNJT4RNthjQhtCI9ND/pSPkQxRFf3BtpQFi0OU/f1LYahV4ozoYUKZmaMRopH7y baKhAAnXL2U5rw4Z7CrgP2Yd/txeTfaYVbn/neyIHddy3FXQhFZQhqqhHC3I33jQQ6C2 eCu6DDVYEXDgyuSWJsfI31r30RFMgOCoY6FIvZZWaS3v91Ge+at7XELVYoquVPmgQsyc yI9cRutLEyLGcuBiHBM5d9f9+a25XR4Cfnj32WrKp/qPCKkXaeL/LR2gb2Xr9xuIfh+Z vXIVF6fx1xwrufGce3/BsiHSyNcHtqezW8Y2c/+LJvgI4+6/FsatYDC0ckiK/Jt+fNC5 0Wbw== X-Gm-Message-State: AOJu0Ywpn1rkPBRAZLdHRqy7tSemnErIPf3sDp7gb10HxWEdBKb4Aehy ImkY6XNxYlUV4W2Qo1klRhWzQxYsB9UAy60eb444uMk5 X-Google-Smtp-Source: AGHT+IFzBhqP61j490rLtUUjCe4xZRx+XzP2d8nTOMPH0WcB5cF7EtmCEmFM0QuaMxPNbrOj/aE6fLqOaOqMdpBfr4I= X-Received: by 2002:a4a:d48b:0:b0:581:e850:6e8 with SMTP id o11-20020a4ad48b000000b00581e85006e8mr12618217oos.1.1698763085081; Tue, 31 Oct 2023 07:38:05 -0700 (PDT) List-Id: Filesystems List-Archive: https://lists.freebsd.org/archives/freebsd-fs List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-fs@freebsd.org MIME-Version: 1.0 Received: by 2002:a8a:d1:0:b0:4f0:1250:dd51 with HTTP; Tue, 31 Oct 2023 07:38:04 -0700 (PDT) In-Reply-To: References: <67FBC292-E83D-4171-BE79-D28D5578F031@mit.edu> From: Mateusz Guzik Date: Tue, 31 Oct 2023 15:38:04 +0100 Message-ID: Subject: Re: vnode_init took over 6 minutes To: John F Carr Cc: Freebsd fs Content-Type: text/plain; charset="UTF-8" X-Spamd-Result: default: False [-3.89 / 15.00]; NEURAL_HAM_LONG(-1.00)[-0.999]; NEURAL_HAM_MEDIUM(-0.97)[-0.974]; NEURAL_HAM_SHORT(-0.92)[-0.918]; DMARC_POLICY_ALLOW(-0.50)[gmail.com,none]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20230601]; MIME_GOOD(-0.10)[text/plain]; MID_RHS_MATCH_FROMTLD(0.00)[]; MLMMJ_DEST(0.00)[freebsd-fs@freebsd.org]; RCVD_TLS_LAST(0.00)[]; MIME_TRACE(0.00)[0:+]; FROM_EQ_ENVFROM(0.00)[]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US]; FREEMAIL_ENVFROM(0.00)[gmail.com]; RCVD_IN_DNSWL_NONE(0.00)[2607:f8b0:4864:20::c2a:from]; DKIM_TRACE(0.00)[gmail.com:+]; RCVD_COUNT_TWO(0.00)[2]; FROM_HAS_DN(0.00)[]; ARC_NA(0.00)[]; RCPT_COUNT_TWO(0.00)[2]; FREEMAIL_FROM(0.00)[gmail.com]; TO_MATCH_ENVRCPT_SOME(0.00)[]; PREVIOUSLY_DELIVERED(0.00)[freebsd-fs@freebsd.org]; TO_DN_ALL(0.00)[]; DWL_DNSWL_NONE(0.00)[gmail.com:dkim] X-Rspamd-Queue-Id: 4SKXmt4tdhz3QXV X-Spamd-Bar: --- On 10/31/23, Mateusz Guzik wrote: > On 10/31/23, John F Carr wrote: >> During a poudriere build control-T showed an awk process was stuck >> for over 6 minutes trying to acquire a lock in vnode_init. >> >> load: 8.58 cmd: awk 51238 [running] 392.88r 0.00u 392.88s 100% 2604k >> __mtx_lock_sleep+0xf8 __mtx_lock_flags+0xa4 vnode_init+0xc3 >> keg_alloc_slab+0x277 zone_import+0x143 cache_alloc+0x3ed >> cache_alloc_retry+0x23 getnewvnode_reserve+0x20 zfs_zget+0x1f >> zfs_dirent_lookup+0x16d zfs_dirlook+0x7f zfs_lookup+0x3e0 >> zfs_freebsd_cachedlookup+0x74 vfs_cache_lookup+0xa7 >> cache_fplookup_noentry+0x241 cache_fplookup+0x575 namei+0x1ea >> vn_open_cred+0x48d >> >> The stack trace was the same for several minutes. System CPU time was >> increasing. >> >> Address vnode_init+0xc3 corresponds to the mtx_lock call here. >> >> vp->v_holdcnt = VHOLD_NO_SMR; >> vp->v_type = VNON; >> mtx_lock(&vnode_list_mtx); >> TAILQ_INSERT_BEFORE(vnode_list_free_marker, vp, v_vnodelist); >> mtx_unlock(&vnode_list_mtx); >> return (0); >> >> Address __mtx_lock_sleep+0xf8 is the instruction after a call to >> lock_delay. >> >> ps says the command line was >> >> /usr/bin/awk -f /usr/bin/awk >> old-default/2023-10-31_08h21m03s/.poudriere.builders >> old-default/2023-10-31_08h21m03s/.poudriere.buildname ... >> >> with the full list of input files exceeding the ~2KB command line length >> limit of ps. >> "/usr/bin/awk" is probably not the real second argument. It would cause >> an >> immediate syntax error. >> >> The hang resolved within a few more minutes and poudriere is continuing >> happily. >> >> I have never seen such behavior before. Code in vfs_subr.c tries not to >> hold the >> vnode_list_mtx lock for too long. >> >> Any thoughts? >> >> >> FreeBSD 13.2-STABLE up through commit b180f0040f95, 24 core 48 thread Zen >> 2, >> zfs pool on SSD connected via 12 Gbps SAS with cache on NVME, 160 GB RAM. >> > > what does "sysctl vfs.vnode" say that and "sysctl vm.uma.VNODE" -- Mateusz Guzik