From nobody Wed Nov 23 14:07:23 2022 X-Original-To: freebsd-dtrace@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 4NHNHQ0hFnz4hTL7 for ; Wed, 23 Nov 2022 14:07:30 +0000 (UTC) (envelope-from markjdb@gmail.com) Received: from mail-qk1-x735.google.com (mail-qk1-x735.google.com [IPv6:2607:f8b0:4864:20::735]) (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 4NHNHN1RPfz4c7c; Wed, 23 Nov 2022 14:07:28 +0000 (UTC) (envelope-from markjdb@gmail.com) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20210112 header.b=gMsMkZyE; spf=pass (mx1.freebsd.org: domain of markjdb@gmail.com designates 2607:f8b0:4864:20::735 as permitted sender) smtp.mailfrom=markjdb@gmail.com; dmarc=none Received: by mail-qk1-x735.google.com with SMTP id p18so12438259qkg.2; Wed, 23 Nov 2022 06:07:28 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=in-reply-to:content-disposition:mime-version:references:message-id :subject:cc:to:from:date:sender:from:to:cc:subject:date:message-id :reply-to; bh=3v5frZsMsb+ciFsk2q3afqGeQomh+JGLaryKZ+vzixs=; b=gMsMkZyEvLR4OaCAWfjcr/rnCPGOT3JXN2a99T6O5zwLhdGaYP0Kg0FsNkvjlQQkM0 vBt6Zn2ZcaWXRyaUcqHLtReJiwWT5T2RP/J3BGypqkrYFZ3COPZrIizq1aRqMff8XvcK 8p3Aagkvz+qUw8C56lBLIo6VvEkqW9vCOyGnqsliLm0u63HgVITqa0afLllEQuy04HJ/ KEpcBV6ba8ylFXSUo7o10TlYI3m5IBsZQ0qNoMjjnZS10cN8fRLzNNb6nqQQdgZSiaPN ILQpplFQ5wmODOLVO7P+00u8NuG6sP44HRSEZhtozLRbioeUM6dnjBO2W4mkfhwmTcx3 KR/g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=in-reply-to:content-disposition:mime-version:references:message-id :subject:cc:to:from:date:sender:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=3v5frZsMsb+ciFsk2q3afqGeQomh+JGLaryKZ+vzixs=; b=bG73vb66zmsWHxPg0TQ0YzypdkOygNJikj+xGeLueT6zuEj2iXMKGF0AUr2TgUtjoM ienNanoRhlvk5O/6sRgK/Ln9pmRQHJgdBd7AU76TxvMF82B/dvvOym+n+wCE7rgrVkZS x51Lg1gtSbJdIWLUojPJLg/irRlXqPyCMu7Qec4MUFTYOSrls/mkcpaRzYQAcZYz2Bpd 2p2MPWi9w0f0xuNPT7+1eh7Lggo8EJ8varlGCa3POAyOCdKuibEfMrl7eR8zZHYgu2zd l2+FSwSKe4xv+Ktn6O68EPe443VZHdm4w6OpwDwynqsNQ9JINfR3cLFGE+q5hrtufEU2 tz3g== X-Gm-Message-State: ANoB5plKDCTIwmnOYdiegvd0bNOkZBaitVPv8OOM9BxnOs1g1GcfVKNa WtpZGsVy+CFalGG2sUCgfPunSa7Mgy0= X-Google-Smtp-Source: AA0mqf6TBTQh4GA8LVLki0UqcBsQqTO0xCeI7I7c1vmuBIkuj+C6oftr7cmwA8GmWFDFm66O24w6cw== X-Received: by 2002:a05:620a:167a:b0:6fb:4d23:bdf9 with SMTP id d26-20020a05620a167a00b006fb4d23bdf9mr24062655qko.576.1669212446751; Wed, 23 Nov 2022 06:07:26 -0800 (PST) Received: from nuc (192-0-220-237.cpe.teksavvy.com. [192.0.220.237]) by smtp.gmail.com with ESMTPSA id y11-20020a37f60b000000b006ce1bfbd603sm11780341qkj.124.2022.11.23.06.07.25 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 23 Nov 2022 06:07:25 -0800 (PST) Date: Wed, 23 Nov 2022 09:07:23 -0500 From: Mark Johnston To: Mateusz Piotrowski <0mp@freebsd.org> Cc: freebsd-dtrace@freebsd.org Subject: Re: In DTrace, why does timestamp increase after a call to chill() but vtimestamp and walltimestamp do not? Message-ID: References: List-Id: A discussion list for developers working on DTrace in FreeBSD List-Archive: https://lists.freebsd.org/archives/freebsd-dtrace List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-dtrace@freebsd.org MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: X-Spamd-Result: default: False [-1.67 / 15.00]; SUBJECT_ENDS_QUESTION(1.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_SHORT(-0.97)[-0.971]; MID_RHS_NOT_FQDN(0.50)[]; FORGED_SENDER(0.30)[markj@freebsd.org,markjdb@gmail.com]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20210112]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36:c]; MIME_GOOD(-0.10)[text/plain]; RCVD_IN_DNSWL_NONE(0.00)[2607:f8b0:4864:20::735:from]; DMARC_NA(0.00)[freebsd.org]; FROM_NEQ_ENVFROM(0.00)[markj@freebsd.org,markjdb@gmail.com]; TO_MATCH_ENVRCPT_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; ARC_NA(0.00)[]; FREEMAIL_ENVFROM(0.00)[gmail.com]; MLMMJ_DEST(0.00)[freebsd-dtrace@freebsd.org]; DKIM_TRACE(0.00)[gmail.com:+]; RCVD_COUNT_THREE(0.00)[3]; TO_DN_SOME(0.00)[]; DWL_DNSWL_NONE(0.00)[gmail.com:dkim]; RCPT_COUNT_TWO(0.00)[2]; MIME_TRACE(0.00)[0:+]; RCVD_TLS_LAST(0.00)[]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US]; RCVD_VIA_SMTP_AUTH(0.00)[] X-Rspamd-Queue-Id: 4NHNHN1RPfz4c7c X-Spamd-Bar: - X-ThisMailContainsUnwantedMimeParts: N On Mon, Nov 21, 2022 at 06:19:16PM +0100, Mateusz Piotrowski wrote: > Hello all, > > I'd like to understand why calling chill() in a DTrace action block increases the timestampvariable, but not vtimestamp and walltimestamp. > Here's an example showing timestamp increasing after a call to chill(): I think you found a bug in dtrace. When a dtrace probe fires and actions attached to that probe are executed, the value of *timestamp is cached in a struct dtrace_mstate on the firing CPU's stack. This means that in D, within a probe body, multiple accesses of *timestamp will return the same cached value. As it turns out, the implementation of chill() will invalidate that cached value, but only for "timestamp", not for walltimestamp, which seems incorrect. Below is an untested patch which should fix your example. I think the behaviour of vtimestamp that you observe is expected. From the description, "The counter does not include the time that is spent in DTrace predicates and actions", so I wouldn't expect it to advance while dtrace_probe() is running. And indeed, it gets advanced once at the beginning of dtrace_probe(). diff --git a/sys/cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c b/sys/cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c index 44a85db65117..cd6ed332af7b 100644 --- a/sys/cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c +++ b/sys/cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c @@ -7082,11 +7082,12 @@ dtrace_action_chill(dtrace_mstate_t *mstate, hrtime_t val) continue; /* - * Normally, we assure that the value of the variable "timestamp" does - * not change within an ECB. The presence of chill() represents an - * exception to this rule, however. + * Normally, we assure that the value of the variables "timestamp" and + * "walltimestamp" do not change within an ECB. The presence of chill() + * represents an exception to this rule, however. */ - mstate->dtms_present &= ~DTRACE_MSTATE_TIMESTAMP; + mstate->dtms_present &= + ~(DTRACE_MSTATE_TIMESTAMP | DTRACE_MSTATE_WALLTIMESTAMP); cpu->cpu_dtrace_chilled += val; }