From nobody Sat Sep 02 17:31:44 2023 X-Original-To: freebsd-current@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 4RdMQV2RYLz4sPsH for ; Sat, 2 Sep 2023 17:31:46 +0000 (UTC) (envelope-from mjguzik@gmail.com) Received: from mail-oo1-xc33.google.com (mail-oo1-xc33.google.com [IPv6:2607:f8b0:4864:20::c33]) (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 4RdMQT4qhMz3CD4 for ; Sat, 2 Sep 2023 17:31:45 +0000 (UTC) (envelope-from mjguzik@gmail.com) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20221208 header.b=pZ+0jlNl; spf=pass (mx1.freebsd.org: domain of mjguzik@gmail.com designates 2607:f8b0:4864:20::c33 as permitted sender) smtp.mailfrom=mjguzik@gmail.com; dmarc=pass (policy=none) header.from=gmail.com Received: by mail-oo1-xc33.google.com with SMTP id 006d021491bc7-57128297bd7so69192eaf.0 for ; Sat, 02 Sep 2023 10:31:45 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20221208; t=1693675904; x=1694280704; 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=5PXO54TSdO/ve/VXiIjHsLTN7siusJIvGf2XBXi4kiI=; b=pZ+0jlNltv/RF1NIDwocLiTvM0CwKWHudxinQ5M9QvMMJd9OTfY3PvDRBu8VqWM0oW WkMk0aasvTEGdn27OtUr3GRdCbygY/WCZZRDdzwhudGLd3E3R7P+5hhd4wkAzlb7TLO6 B5milFWazuzE9txI/iq7L4HXYr0qlAjVLqSTUcF3li+7I6LhNUYKd74MvhIyScFBkl57 lpU8Evo3do7JlMAbwk5pdfhwuCxm/WIPke5XbqMUB8wb8XKz6TvPwVX3keR5mHwIe/TH 3f43lBklil4TySgxpwLo9w/T5otW6/wFQ4661wP/kIYviol/5pCxIMgVixZZO82+vHoN JIjQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1693675904; x=1694280704; 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=5PXO54TSdO/ve/VXiIjHsLTN7siusJIvGf2XBXi4kiI=; b=LTpqy2kloDsydSO1aMy2Dsr1MZs/WLpyl9qkl/QtPXPi3Hu9/IS7sypJKQ23/MViok 9pJBRthJLWUs0v2mzGPWXcRtoVf4x21TxkmFAQagjWIwTEvCKZqd779P/bqVhpO6erzD fZB0xBgBi6rK2QsSEVJi4ZdXqM5ClTXvBAd2p2P+LOBaxw2gc9bRyr2PJS+3V33+QbrK AH0+s+eaRM4E4OzU84JYPJ6+vCqHWCOZH1xoX0PirKgtE3wKIFWI7cvZF+EcsbmAEltD AKeKY3oUjYD73S6Kn05smsRX64G7v4Fg5iLV2QLz/kYHHszNvzj5qj+eohWXe8eV3JTD CkBw== X-Gm-Message-State: AOJu0Yw3KXMIOu2kuosg2fiXY5ej3KgAlu7DDnuEDQ7eUn4rEj7JinyB bOJU3/i8CT10BPOxCB2YE5LdSETaMqAIHO67ihY= X-Google-Smtp-Source: AGHT+IFs2YjiEFcqOtParfQEmYs6W0ugqw/cfKrLa2syv94SSiMNl1N2YnMhE/KerXtAez6Dw8uy61ics2WaMHS2CSo= X-Received: by 2002:a4a:9b88:0:b0:571:1c44:c9b8 with SMTP id x8-20020a4a9b88000000b005711c44c9b8mr4769043ooj.3.1693675904559; Sat, 02 Sep 2023 10:31:44 -0700 (PDT) List-Id: Discussions about the use of FreeBSD-current List-Archive: https://lists.freebsd.org/archives/freebsd-current List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-current@freebsd.org MIME-Version: 1.0 Received: by 2002:a8a:60c:0:b0:4f0:1250:dd51 with HTTP; Sat, 2 Sep 2023 10:31:44 -0700 (PDT) In-Reply-To: References: <95e9f65b-58c4-ef3a-a5d1-b794179e4252@gmail.com> From: Mateusz Guzik Date: Sat, 2 Sep 2023 19:31:44 +0200 Message-ID: Subject: Re: kernel 100% CPU, and ports-mgmt/poudriere-devel 'Inspecting ports tree for modifications to git checkout...' for an extraordinarily long time To: Graham Perrin Cc: FreeBSD-CURRENT Content-Type: text/plain; charset="UTF-8" X-Spamd-Bar: --- X-Spamd-Result: default: False [-4.00 / 15.00]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_SHORT(-1.00)[-1.000]; NEURAL_HAM_LONG(-1.00)[-1.000]; DMARC_POLICY_ALLOW(-0.50)[gmail.com,none]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20221208]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36:c]; MIME_GOOD(-0.10)[text/plain]; FROM_HAS_DN(0.00)[]; FREEMAIL_FROM(0.00)[gmail.com]; PREVIOUSLY_DELIVERED(0.00)[freebsd-current@freebsd.org]; ARC_NA(0.00)[]; RCVD_IN_DNSWL_NONE(0.00)[2607:f8b0:4864:20::c33:from]; TO_MATCH_ENVRCPT_SOME(0.00)[]; DWL_DNSWL_NONE(0.00)[gmail.com:dkim]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US]; MLMMJ_DEST(0.00)[freebsd-current@freebsd.org]; DKIM_TRACE(0.00)[gmail.com:+]; TO_DN_ALL(0.00)[]; MID_RHS_MATCH_FROMTLD(0.00)[]; RCVD_TLS_LAST(0.00)[]; RCPT_COUNT_TWO(0.00)[2]; FROM_EQ_ENVFROM(0.00)[]; FREEMAIL_TO(0.00)[gmail.com]; FREEMAIL_ENVFROM(0.00)[gmail.com]; MIME_TRACE(0.00)[0:+]; RCVD_COUNT_TWO(0.00)[2] X-Rspamd-Queue-Id: 4RdMQT4qhMz3CD4 On 9/2/23, Graham Perrin wrote: > On 02/09/2023 10:17, Mateusz Guzik wrote: >> On 9/2/23, Graham Perrin wrote: >>> Some inspections are extraordinarily time-consuming. Others complete >>> very quickly, as they should. >>> >>> One recent inspection took more than half an hour. >>> >>> Anyone else? >>> >>> A screenshot: >>> >>> % pkg iinfo poudriere-devel >>> poudriere-devel-3.3.99.20220831 >>> % uname -aKU >>> FreeBSD mowa219-gjp4-8570p-freebsd 15.0-CURRENT FreeBSD 15.0-CURRENT >>> amd64 1500000 #10 main-n265053-315ee00fa961-dirty: Mon Aug 28 06:22:31 >>> BST 2023 >>> grahamperrin@mowa219-gjp4-8570p-freebsd:/usr/obj/usr/src/amd64.amd64/sys/GENERIC-NODEBUG >>> >>> amd64 1500000 1500000 >>> % >> get a flamegraph with dtrace >> >> https://github.com/brendangregg/FlameGraph > > Thanks! TIL, it's ported. > > Graph attached, as a PNG, although I don't know whether it'll be useful, > because I began the trace /after/ the issue became observable. > > Will it be more meaningful to begin a trace and then reproduce the issue > (before the trace ends)? > > ---- > > root@mowa219-gjp4-8570p-freebsd:/tmp # dtrace -x stackframes=100 -n > 'profile-997 /arg0/ { @[stack()] = count(); } tick-60s { exit(0); }' -o > out.kern_stacks > dtrace: description 'profile-997 ' matched 2 probes > root@mowa219-gjp4-8570p-freebsd:/tmp # stackcollapse.pl out.kern_stacks > > out.kern_folded > root@mowa219-gjp4-8570p-freebsd:/tmp # flamegraph.pl out.kern_folded > > kernel.svg > root@mowa219-gjp4-8570p-freebsd:/tmp # > Looks like you have a lot of unrelated traffic in there. Run this script: #pragma D option dynvarsize=32m profile:::profile-997 /execname == "find"/ { @oncpu[stack(), "oncpu"] = count(); } /* * The p_flag & 0x4 test filters out kernel threads. */ sched:::off-cpu /execname == "find"/ { self->ts = timestamp; } sched:::on-cpu /self->ts/ { @offcpu[stack(30), "offcpu"] = sum(timestamp - self->ts); self->ts = 0; } dtrace:::END { normalize(@offcpu, 1000000); printa("%k\n%s\n%@d\n\n", @offcpu); printa("%k\n%s\n%@d\n\n", @oncpu); } dtrace -s script.d -o out this can be fed to generate a flamegraph the same way; upload it to freefall -- Mateusz Guzik