From owner-freebsd-current@freebsd.org Thu Nov 28 20:52:37 2019 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 5C9061B7A2E for ; Thu, 28 Nov 2019 20:52:37 +0000 (UTC) (envelope-from pen@lysator.liu.se) Received: from mail.lysator.liu.se (mail.lysator.liu.se [130.236.254.3]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 47P8wK6HZmz44w8 for ; Thu, 28 Nov 2019 20:52:33 +0000 (UTC) (envelope-from pen@lysator.liu.se) Received: from mail.lysator.liu.se (localhost [127.0.0.1]) by mail.lysator.liu.se (Postfix) with ESMTP id F279B4000D for ; Thu, 28 Nov 2019 21:52:30 +0100 (CET) Received: from [192.168.1.132] (h-201-140.A785.priv.bahnhof.se [98.128.201.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.lysator.liu.se (Postfix) with ESMTPSA id DB0644000C for ; Thu, 28 Nov 2019 21:52:30 +0100 (CET) From: Peter Eriksson Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Mime-Version: 1.0 (Mac OS X Mail 13.0 \(3601.0.10\)) Subject: Best way to print something from the kernel at 1s intervals? Message-Id: Date: Thu, 28 Nov 2019 21:52:30 +0100 To: freebsd-current@freebsd.org X-Mailer: Apple Mail (2.3601.0.10) X-Virus-Scanned: ClamAV using ClamSMTP X-Rspamd-Queue-Id: 47P8wK6HZmz44w8 X-Spamd-Bar: -- Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=pass (policy=none) header.from=liu.se; spf=pass (mx1.freebsd.org: domain of pen@lysator.liu.se designates 130.236.254.3 as permitted sender) smtp.mailfrom=pen@lysator.liu.se X-Spamd-Result: default: False [-2.55 / 15.00]; ARC_NA(0.00)[]; SUBJECT_ENDS_SPACES(0.50)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; FROM_HAS_DN(0.00)[]; R_SPF_ALLOW(-0.20)[+a:mail.lysator.liu.se]; TO_MATCH_ENVRCPT_ALL(0.00)[]; MIME_GOOD(-0.10)[text/plain]; PREVIOUSLY_DELIVERED(0.00)[freebsd-current@freebsd.org]; TO_DN_NONE(0.00)[]; RCPT_COUNT_ONE(0.00)[1]; NEURAL_HAM_LONG(-1.00)[-1.000,0]; RCVD_COUNT_THREE(0.00)[3]; MIME_TRACE(0.00)[0:+]; MV_CASE(0.50)[]; RCVD_IN_DNSWL_MED(-0.20)[3.254.236.130.list.dnswl.org : 127.0.11.2]; DMARC_POLICY_ALLOW(-0.50)[liu.se,none]; NEURAL_HAM_MEDIUM(-1.00)[-1.000,0]; RCVD_TLS_LAST(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; SUBJECT_ENDS_QUESTION(1.00)[]; ASN(0.00)[asn:2843, ipnet:130.236.0.0/16, country:SE]; MID_RHS_MATCH_FROM(0.00)[]; IP_SCORE(-1.55)[ipnet: 130.236.0.0/16(-4.28), asn: 2843(-3.42), country: SE(-0.03)] X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.29 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: Thu, 28 Nov 2019 20:52:37 -0000 I=E2=80=99ve been looking into the =E2=80=9Ckernel looks to be hung at = reboot=E2=80=9D problem at bit. Adding a lot of printf() calls to the = relevant parts it looks like it actually isn=E2=80=99t hung but busy = unmounting filesystems (which we have thousands of), flushing disk = caches, calling registered callbacks and stuff and sometimes it takes a = bit longer than usual - probably due to ZFS having stuff queued up that = needs to be written to disk before it finishes=E2=80=A6 Anyway, I=E2=80=99d like to propose that we add some kind of = counter/printf() calls in that code area so we can see that things are = indeed progressing. However, I=E2=80=99d probably prefer not to print = _every_ filesystem (or registered callbacks - a lot of those...) - that = generates a lot of output (tried that :-) but something like: Unmounting filesystems: 1234 done (With the "1234 done=E2=80=9D updated something like once per second). What=E2=80=99s the right/best way to do that from the kernel? In user = space I=E2=80=99d just call time(&t) at some convenient points and only = print something if =E2=80=9Ct=E2=80=9D has changed. :-) - Peter