From owner-freebsd-current@freebsd.org Fri Apr 2 21:47:36 2021 Return-Path: Delivered-To: freebsd-current@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 E5BD55B3682 for ; Fri, 2 Apr 2021 21:47:36 +0000 (UTC) (envelope-from mjguzik@gmail.com) Received: from mail-lj1-x229.google.com (mail-lj1-x229.google.com [IPv6:2a00:1450:4864:20::229]) (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 1O1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4FBtvD5vL3z4RtM; Fri, 2 Apr 2021 21:47:36 +0000 (UTC) (envelope-from mjguzik@gmail.com) Received: by mail-lj1-x229.google.com with SMTP id y1so6763633ljm.10; Fri, 02 Apr 2021 14:47:36 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:in-reply-to:references:from:date:message-id:subject:to :cc; bh=ZyJ/zrIw4S6d6ZbsQ545uk/G4FVPocI6kLT05TwOdxw=; b=dhsin5SsGuKjZKnHlshZ0gBcH6v4tXahKdf7nasgtnBOMa8okzQX6da0Vuiwz2Beb2 zoAGh5Ef0dOufRMc9Qeoqtq7dOj6AHQ/B1fnDb8rN8d/qdu6q9qU6cl9E1aXMZqYCSpK TMpC4+P+gsFrwnO6+eRp47sww2Vir0wtxZ1uM960cwb+86L+rOrirlkIuXdZIXb1YykM +vO52wXN+Rq+tbjtC7iNVqQ9UUb/N+Ibd1zWd/uaEqOsOzCqI8Z6Nqa4Di7hzu7E3LDY r/ythazN31hPUWh+fZtstL4o0uB6v9DGZ/fuqVxFh4e8NwAuW45sJv4zCtGhmfkfx54C 1Ubg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to:cc; bh=ZyJ/zrIw4S6d6ZbsQ545uk/G4FVPocI6kLT05TwOdxw=; b=SLgXlhbgX7HybBYE7BC4i0OAQkBSf84zb6Y4zBDAIxRR6C4pttt1OiML1VcP3dGo3y 4mAMw3cT4Dw0MVpqSE1dRzJdN2YyqTwrAGqu6WbLQKSo2cJ3CVu3XrZjSJw+IaMN3A3Y AOSHrXI5/2vPUzkKshlXjvc9Urffo7VwwDFwDpSWaXU1pqYSS2VXGYquZR3NYg/yly02 SbUl+P7hDU+oW+5aQ0CgTqMnQfBLyauAaA9lsa8N8jpN9cyfpzF9dizIjbz232XcrXhS cJl2qBG0GasgdV6THxA6knAPxvK8HEK62qqjksq8PMFNSzzLgQQOZ14/3Ww2Oug90rqx GfXg== X-Gm-Message-State: AOAM531rkYFtExt8ejhCrXseuslSIOcD7+aJr6p591614m/Y+zrlZgBH v30Yr01/vuGDOitY54AnLb60MGBve0aMr+wCZYmKs1Z1 X-Google-Smtp-Source: ABdhPJyLCV7hX/e6bZ15LXlU+Q6cZcCGF05da5bAEFOrhZBmlU79X9E1a7vD2a9jCLLd9buT7xVDkBs1QFq1Gea2bkU= X-Received: by 2002:a2e:8709:: with SMTP id m9mr9056561lji.483.1617400053907; Fri, 02 Apr 2021 14:47:33 -0700 (PDT) MIME-Version: 1.0 Received: by 2002:a2e:b54e:0:0:0:0:0 with HTTP; Fri, 2 Apr 2021 14:47:33 -0700 (PDT) In-Reply-To: <494d4aab-487b-83c9-03f3-10cf470081c5@freebsd.org> References: <58bea0f0-5c3d-4263-ebee-f939a7e169e9@freebsd.org> <494d4aab-487b-83c9-03f3-10cf470081c5@freebsd.org> From: Mateusz Guzik Date: Fri, 2 Apr 2021 23:47:33 +0200 Message-ID: Subject: Re: [SOLVED] Re: Strange behavior after running under high load To: Stefan Esser Cc: FreeBSD CURRENT Content-Type: text/plain; charset="UTF-8" X-Rspamd-Queue-Id: 4FBtvD5vL3z4RtM X-Spamd-Bar: ---- Authentication-Results: mx1.freebsd.org; none X-Spamd-Result: default: False [-4.00 / 15.00]; REPLY(-4.00)[] X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 02 Apr 2021 21:47:37 -0000 On 4/2/21, Stefan Esser wrote: > Am 28.03.21 um 16:39 schrieb Stefan Esser: >> After a period of high load, my now idle system needs 4 to 10 seconds to >> run any trivial command - even after 20 minutes of no load ... >> >> >> I have run some Monte-Carlo simulations for a few hours, with initially > 35 >> processes running in parallel for some 10 seconds each. >> >> The load decreased over time since some parameter sets were faster to >> process. >> All in all 63000 processes ran within some 3 hours. >> >> When the system became idle, interactive performance was very bad. >> Running >> any trivial command (e.g. uptime) takes some 5 to 10 seconds. Since I >> have >> to have this system working, I plan to reboot it later today, but will >> keep >> it in this state for some more time to see whether this state persists or >> whether the system recovers from it. >> >> Any ideas what might cause such a system state??? > > Seems that Mateusz Guzik was right to mention performance issues when > the system is very low on vnodes. (Thanks!) > > I have been able to reproduce the issue and have checked vnode stats: > > kern.maxvnodes: 620370 > kern.minvnodes: 155092 > vm.stats.vm.v_vnodepgsout: 6890171 > vm.stats.vm.v_vnodepgsin: 18475530 > vm.stats.vm.v_vnodeout: 228516 > vm.stats.vm.v_vnodein: 1592444 > vfs.wantfreevnodes: 155092 > vfs.freevnodes: 47 <----- obviously too low ... > vfs.vnodes_created: 19554702 > vfs.numvnodes: 621284 > vfs.cache.debug.vnodes_cel_3_failures: 0 > vfs.cache.stats.heldvnodes: 6412 > > The freevnodes value stayed in this region over several minutes, with > typical program start times (e.g. for "uptime") in the region of 10 to > 15 seconds. > > After rising maxvnodes to 2,000,000 form 600,000 the system performance > is restored and I get: > > kern.maxvnodes: 2000000 > kern.minvnodes: 500000 > vm.stats.vm.v_vnodepgsout: 7875198 > vm.stats.vm.v_vnodepgsin: 20788679 > vm.stats.vm.v_vnodeout: 261179 > vm.stats.vm.v_vnodein: 1817599 > vfs.wantfreevnodes: 500000 > vfs.freevnodes: 205988 <----- still a lot higher than wantfreevnodes > vfs.vnodes_created: 19956502 > vfs.numvnodes: 912880 > vfs.cache.debug.vnodes_cel_3_failures: 0 > vfs.cache.stats.heldvnodes: 20702 > > I do not know why the performance impact is so high - there are a few > free vnodes (more than required for the shared libraries to start e.g. > the uptime program). Most probably each attempt to get a vnode triggers > a clean-up attempt that runs for a significant time, but has no chance > to actually reach near the goal of 155k or 500k free vnodes. > It is high because of this: msleep(&vnlruproc_sig, &vnode_list_mtx, PVFS, "vlruwk", hz); i.e. it literally sleeps for 1 second. The vnode limit is probably too conservative and behavior when limit is reached is rather broken. Probably the thing to do is to let allocations go through while kicking vnlru to free some stuff up. I'll have to sleep on it. > Anyway, kern.maxvnodes can be changed at run-time and it is thus easy > to fix. It seems that no message is logged to report this situation. > A rate limited hint to rise the limit should help other affected users. > > Regards, STefan > > -- Mateusz Guzik