From owner-freebsd-current@freebsd.org Fri Nov 29 22:22:29 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 08DB51BE34F for ; Fri, 29 Nov 2019 22:22:29 +0000 (UTC) (envelope-from ian@freebsd.org) Received: from outbound2m.ore.mailhop.org (outbound2m.ore.mailhop.org [54.149.155.156]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) server-signature RSA-PSS (4096 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 47Ppsc5yHCz4NQy for ; Fri, 29 Nov 2019 22:22:28 +0000 (UTC) (envelope-from ian@freebsd.org) ARC-Seal: i=1; a=rsa-sha256; t=1575066147; cv=none; d=outbound.mailhop.org; s=arc-outbound20181012; b=h0tYAkqNAiZzDjii1VDD1EdiEll66Sw4z8uIZzuMYhUWe3Ij3pEfUCQH0+QXIOvgqdYMrKSuAePhD nGMLFHzC60wx0zYZHdFrrghu+xJRE0YxrfHQNbzsH6D6oI6Ft+vaX/On8/8s7Ag1AiZSFMFUwKICo+ juRawbbD/EJCoKUPffwihYJsEIoH1LkE1FX0aD2YCQbfIXDnrz8cBeTP95Z5s0WgTwa3AadOjFFMM0 DZ45Ew2TgdqZJsJbCRhiWJL/MaThM4lX6q0ZQJmTOP4lq/rLyePBGvCtsGeiI6e3167g6awigYRif1 C/Hu4i1GxUgOwU1bYPKdaujdwozueOQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=outbound.mailhop.org; s=arc-outbound20181012; h=content-transfer-encoding:mime-version:content-type:references:in-reply-to: date:to:from:subject:message-id:dkim-signature:from; bh=d2iuLSDbprIeWW+b5WOC3IZl+c8O03rACeJNXnFDsXM=; b=qhK634vCluWPNVfGkzcKF1fH0+Z/GoII0jZrLPJi0nc7YlSaMpjf3lTbgHblzXz6SwfHw1/tRC0JP HMIOXA03n7O/XNbs+5pjguLKMcuh5nuicfwoAkXVgd1lFQK0T4kxWrOzk1rjVjfcA8oca0vCRCSEEz KaRdeg8lwF4S/ropex6mjBeyKLgO/1HYQH3gFzX+idKfl3bl9vM+/CFwZslCrZAPQP5a4Qnp7t43WG bQTBG8M+Ku+NBZ/FWi0XpD7oBRbAXzJCr/wl5RLtpaOj4tix2xkQIxM8JWJyrjW3g2eG2L++lE/rY1 sIQczjyfQTk82EZ0u/k4dvYOlSYjxhQ== ARC-Authentication-Results: i=1; outbound4.ore.mailhop.org; spf=softfail smtp.mailfrom=freebsd.org smtp.remote-ip=67.177.211.60; dmarc=none header.from=freebsd.org; arc=none header.oldest-pass=0; DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=outbound.mailhop.org; s=dkim-high; h=content-transfer-encoding:mime-version:content-type:references:in-reply-to: date:to:from:subject:message-id:from; bh=d2iuLSDbprIeWW+b5WOC3IZl+c8O03rACeJNXnFDsXM=; b=QCjnT54+NNqTyD/fBIkHDFNWNqm1LqSoueO9sOaC3fIzdJNTWhlw6bd0V0BQ3RIAsesEFczTQN+tx 20gh4kHsv4Pj8H+9mPSym1fNZC3Qn6LFesIMGytC8RXgs2nZnPMs2BzRg8BYV3VJ5yoQzrR13o4YAP 8TC7UGYFyRxf/TFnuBWEI52M3e1QiZd5p/RmsSXW25Tp+KhVyq6vJxkkprsRQFbDJm6ghXJ03hsXgb YrVF4mHNI8wiT5YJiy4kCvWVb7F9mIYOCRqzosuzEKMX4xa7aKQJjg9aODJMmx7O/shPrwEqRDchk7 3lKOI4vBjrCQRheU6cn6S2Fo7lGK3gg== X-MHO-RoutePath: aGlwcGll X-MHO-User: b77d07af-12f6-11ea-829e-79a40d15cccd X-Report-Abuse-To: https://support.duocircle.com/support/solutions/articles/5000540958-duocircle-standard-smtp-abuse-information X-Originating-IP: 67.177.211.60 X-Mail-Handler: DuoCircle Outbound SMTP Received: from ilsoft.org (unknown [67.177.211.60]) by outbound4.ore.mailhop.org (Halon) with ESMTPSA id b77d07af-12f6-11ea-829e-79a40d15cccd; Fri, 29 Nov 2019 22:22:26 +0000 (UTC) Received: from rev (rev [172.22.42.240]) by ilsoft.org (8.15.2/8.15.2) with ESMTP id xATMMNR0085726; Fri, 29 Nov 2019 15:22:23 -0700 (MST) (envelope-from ian@freebsd.org) Message-ID: Subject: Re: Best way to print something from the kernel at 1s intervals? From: Ian Lepore To: Peter Eriksson , freebsd-current@freebsd.org Date: Fri, 29 Nov 2019 15:22:23 -0700 In-Reply-To: <057870D3-B59E-47FB-A832-A72DC6F54AFA@lysator.liu.se> References: <057870D3-B59E-47FB-A832-A72DC6F54AFA@lysator.liu.se> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.28.5 FreeBSD GNOME Team Mime-Version: 1.0 Content-Transfer-Encoding: 8bit X-Rspamd-Queue-Id: 47Ppsc5yHCz4NQy X-Spamd-Bar: - Authentication-Results: mx1.freebsd.org; none X-Spamd-Result: default: False [-1.79 / 15.00]; local_wl_from(0.00)[freebsd.org]; NEURAL_HAM_MEDIUM(-0.89)[-0.887,0]; ASN(0.00)[asn:16509, ipnet:54.148.0.0/15, country:US]; NEURAL_HAM_LONG(-0.91)[-0.907,0] 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: Fri, 29 Nov 2019 22:22:29 -0000 On Fri, 2019-11-29 at 23:10 +0100, Peter Eriksson wrote: > I love dtrace, but I seriously doubt that it could be used it for > this. This is the absolutely last code that executes at kernel > shutdown/reboot. All other processes are terminated when this is > happening... > > Basically the code done in kern_reboot() (and stuff it calls) in > /usr/src/sys/kern/kern_shutdown.c > > This code in kern_reboot(): > ... > > EVENTHANDLER_INVOKE(shutdown_pre_sync, howto); > > > > /* > > * Now sync filesystems > > */ > > if (!cold && (howto & RB_NOSYNC) == 0 && once == 0) { > > once = 1; > > bufshutdown(show_busybufs); > > } > > > > print_uptime(); > > > > cngrab(); > > > > /* > > * Ok, now do things that assume all filesystem activity has > > * been completed. > > */ > > EVENTHANDLER_INVOKE(shutdown_post_sync, howto); > > > > if ((howto & (RB_HALT|RB_DUMP)) == RB_DUMP && !cold && > > !dumping) > > doadump(TRUE); > > > > /* Now that we're going to really halt the system... */ > > EVENTHANDLER_INVOKE(shutdown_final, howto); > > What I’ve seen is that the three different EVENTHANDLER_INVOKE() all > can cause a lot of calls that can take a long time. As can > bufshutdown(), probably when it calls vfs_unmountall() to unmount all > filesystems. > > We’re talking like 5-20 minutes (or more). I’ve not really timed it. > > I have a feeling it sometimes is due to transactions stored up in the > ZFS filesystems that the system tries to “run” so it doesn’t have to > do it at mount() time after the reboot. If I reset the machine while > it is busy doing this then sometimes the “zfs mount -a” takes very > long time at boot instead. > > Hmm.. I should be able to use the getnanouptime() call to get a > “clock” to look for (it’s used in print_uptime()). As long as the > clock isn’t stopped at this time in the shutdown sequence atleast :-) > > *Time to write some code and test this* :-) > If you want to throttle something to once a second (or some number of integer seconds) the kernel has a global variable named time_sec, (in sys/time.h), watch for it to change. -- Ian