From nobody Fri Jun 03 17:09:40 2022 X-Original-To: freebsd-hackers@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 57A6D1BD9617 for ; Fri, 3 Jun 2022 17:09:53 +0000 (UTC) (envelope-from markjdb@gmail.com) Received: from mail-qt1-x835.google.com (mail-qt1-x835.google.com [IPv6:2607:f8b0:4864:20::835]) (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 4LF8Wg1dqVz4TT9; Fri, 3 Jun 2022 17:09:50 +0000 (UTC) (envelope-from markjdb@gmail.com) Received: by mail-qt1-x835.google.com with SMTP id hf10so6070092qtb.7; Fri, 03 Jun 2022 10:09:50 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:date:from:to:cc:subject:message-id:references:mime-version :content-disposition:in-reply-to; bh=E/tyT0+6SyyulEL1AOQSsWHW3cEPk3QF49NIGDS8CcI=; b=Nj2CtAgbgCz6wL2QC1xponXfVvjEY+RGfi6P+slmx1YmasXbxq+gXZcx7SxKnjpQuN SdZnM3MCe7KrAn61ADaOBT6ZcSUCyO4GISRXNcOG8ozJTe3QpK8tpjn3eu08OlXNM9+A xN3eomIlyhAEsuignIzpektWabazNocfBMcGiHyVNep4jhRXy5nE2/77gT1CqqhBXK3/ mQYaS421B4ZjYXtaHymmM2AT7DZwArxS8yL60c5M2nA/JP1/p54O6mrqGKU+w938oD19 pYV9z+72V4vSquUfqbOfHNT5hWs4mF5bcHhWNNTPdeKDW5RYgC8B1dGg0nAfp/nb3tN5 Ncww== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:date:from:to:cc:subject:message-id :references:mime-version:content-disposition:in-reply-to; bh=E/tyT0+6SyyulEL1AOQSsWHW3cEPk3QF49NIGDS8CcI=; b=mcRO4BquBX2eL5zA0iRSWIkq4v/6hCngets2gSviFrH0z5YYFHKve1ZVEc2uuBzx0P LQAqjpBwm5CndzZC1IcuomgbCoY+RtKsW3+WPNIxumNA86uOIg03awBmkpVib8UXD+r/ FzgFRxgVU22z9CpdBURbdjgt3YiIE+quf5i7BA/sZcusY1g4Wt1mL3LpaMOsxYljTYKh x/U75EuuS1TDBzECAxsYo4AJjvQNKUipMnUPqb56FyxUWzwHBQ31AaFmfdRMgBHPvxSq nRgl+fc7y5BrA/l2VUr+Lke5JHfBoKksT1On/hx76TgQSY7Cx1ioQvjNUwYJtE/uy4pQ KA8Q== X-Gm-Message-State: AOAM530CD/y//vJI/YoEvh/8ZNRJ+omNRAMxyMjbdclk90Y9g/59z27Y a4R9u4rbiXe/ifuf0rDYQz7qmYIfcK8= X-Google-Smtp-Source: ABdhPJy7iMOKjLAh9Qr0iY2mxp6mJ2FbTWTeaKBtoAY9I8upzcufdcSMWtMdjs3o9SkELb6LsMJ0HA== X-Received: by 2002:ac8:5982:0:b0:2f3:b838:cdda with SMTP id e2-20020ac85982000000b002f3b838cddamr8500492qte.119.1654276183899; Fri, 03 Jun 2022 10:09:43 -0700 (PDT) Received: from nuc (198-84-189-58.cpe.teksavvy.com. [198.84.189.58]) by smtp.gmail.com with ESMTPSA id f6-20020a05622a104600b002f39b99f6a3sm5461899qte.61.2022.06.03.10.09.42 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 03 Jun 2022 10:09:43 -0700 (PDT) Date: Fri, 3 Jun 2022 13:09:40 -0400 From: Mark Johnston To: Alan Somers Cc: FreeBSD Hackers Subject: Re: Dtrace, Rust, and LLVM13 Message-ID: References: List-Id: Technical discussions relating to FreeBSD List-Archive: https://lists.freebsd.org/archives/freebsd-hackers List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-hackers@freebsd.org MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: X-Rspamd-Queue-Id: 4LF8Wg1dqVz4TT9 X-Spamd-Bar: -- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20210112 header.b=Nj2CtAgb; dmarc=none; spf=pass (mx1.freebsd.org: domain of markjdb@gmail.com designates 2607:f8b0:4864:20::835 as permitted sender) smtp.mailfrom=markjdb@gmail.com X-Spamd-Result: default: False [-2.50 / 15.00]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20210112]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; FROM_HAS_DN(0.00)[]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36:c]; TO_MATCH_ENVRCPT_ALL(0.00)[]; MIME_GOOD(-0.10)[text/plain]; MID_RHS_NOT_FQDN(0.50)[]; DMARC_NA(0.00)[freebsd.org]; NEURAL_HAM_LONG(-1.00)[-1.000]; RCVD_COUNT_THREE(0.00)[3]; TO_DN_ALL(0.00)[]; DKIM_TRACE(0.00)[gmail.com:+]; RCPT_COUNT_TWO(0.00)[2]; RCVD_IN_DNSWL_NONE(0.00)[2607:f8b0:4864:20::835:from]; NEURAL_HAM_SHORT(-0.80)[-0.802]; MLMMJ_DEST(0.00)[freebsd-hackers]; FORGED_SENDER(0.30)[markj@freebsd.org,markjdb@gmail.com]; MIME_TRACE(0.00)[0:+]; FREEMAIL_ENVFROM(0.00)[gmail.com]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US]; FROM_NEQ_ENVFROM(0.00)[markj@freebsd.org,markjdb@gmail.com]; RCVD_TLS_ALL(0.00)[]; DWL_DNSWL_NONE(0.00)[gmail.com:dkim] X-ThisMailContainsUnwantedMimeParts: N On Thu, Jun 02, 2022 at 03:27:48PM -0600, Alan Somers wrote: > On Thu, Jun 2, 2022 at 2:55 PM Mark Johnston wrote: > > > > On Wed, Jun 01, 2022 at 09:15:28PM -0600, Alan Somers wrote: > > > The best way to profile a Rust program on FreeBSD is with Brendan > > > Gregg's Flamegraph[1]. This is based on dtrace's ustack() function. > > > It used to work great. However, Rust v1.56.0 is based on LLVM13[2] > > > and now dtrace can't print user stacks anymore. For example, > > > > > > With Rust 1.55.0 > > > libc.so.7`__je_malloc_mutex_prefork+0x124 > > > libc.so.7`__je_arena_prefork7+0x73 > > > libc.so.7`_malloc_prefork+0x15b > > > libthr.so.3`0x392e4a8c4686 > > > libthr.so.3`_fork+0x18 > > > test-dad15ed382b075cf`nix::unistd::fork::h358225d652a86eab+0xe > > > test-dad15ed382b075cf`test::test_unistd::test_fork_and_waitpid::hb93c7cdf2b79d680+0x36 > > > test-dad15ed382b075cf`test::test_unistd::test_fork_and_waitpid::_$u7b$$u7b$closure$u7d$$u7d$::h329a121974ff9291+0x11 > > > test-dad15ed382b075cf`core::ops::function::FnOnce::call_once::h2261827bcba63036+0x11 > > > test-dad15ed382b075cf`test::__rust_begin_short_backtrace::hefb7644d11da2ff9+0xa > > > test-dad15ed382b075cf`test::run_test::run_test_inner::_$u7b$$u7b$closure$u7d$$u7d$::hdaa0fb71aac8d97e+0x2f3 > > > test-dad15ed382b075cf`std::sys_common::backtrace::__rust_begin_short_backtrace::h8bcc057a546c1087+0xce > > > test-dad15ed382b075cf`core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::hf7d978d08be459d0+0x6a > > > test-dad15ed382b075cf`std::sys::unix::thread::Thread::new::thread_start::h6b52ca0eca213387+0x2b > > > > What are the identifiers at the end of each function? > > You mean the hex number that comes before the offset? I think the > Rust compiler uses those to disambiguate closures, which would > otherwise have the same name. However, not all of these functions are > closures. Maybe Rust always generates that identifier anyway? Ok. Was just curious to know if there's something there that we should be demangling, but it seems not. > > > libthr.so.3`0x392e4a8c3a7a > > > > > > With Rust 1.56.0 > > > libc.so.7`__je_malloc_mutex_prefork+0x124 > > > libc.so.7`__je_arena_prefork7+0x73 > > > libc.so.7`_malloc_prefork+0x15b > > > libthr.so.3`0x1106cebc6686 > > > libthr.so.3`_fork+0x18 > > > test-b377ad62cc9e0624`nix::unistd::fork::hbf1ed55b658aa870+0xa > > > 0x8 > > > 0xcccccccccccccccc > > > > > > See? dtrace still prints the C part of the stack, but it only prints > > > one or sometimes two frames of the Rust stack. > > > > ustack() unwinds the stack using the frame pointer saved in each stack > > frame. It'll fail to unwind code compiled without a frame pointer, > > e.g., if -fomit-frame-pointer is specified to a C/C++ compiler. For > > this and similar reasons, we compile the base system with > > -fno-omit-frame-pointer by default. > > > > > I'm not a compiler guy, so I don't know how to fix it. I don't even > > > know if the problem lies in Rust or dtrace. Would any of you smart > > > people be able to help here? This is a pretty important feature for > > > Rust development. > > > > I'd guess that Rust started omitting use of the frame pointer in > > generated code. This commit seems to indicate that that's the case: > > https://github.com/rust-lang/rust/pull/48786/commits/5b800c231f45fcd823a3e958bb942cd620ceb3e0 > > Though, it's rather old. I'm not sure why the problem appeared only > > now. So maybe the problem is elsewhere, but the commit log also > > mentions a -Cforce-frame-pointers flag that you could try. > > > > While it's possible to unwind the stack without using a frame pointer, a > > frame pointer makes doing so dead simple. ustack() does the unwinding > > in the kernel, in DTrace probe context, and text addresses are resolved > > to symbol names in userspace. So it's generally desirable to keep the > > implementation simple. > > That works! Setting RUSTFLAGS="-C force-frame-pointers" allows dtrace > to unwind the stacks in the resulting binaries. However, it still > doesn't work when I build a Rust shared library. Any idea why that > might be? Doesn't work as in, the trace stops early like in your earlier example? Or names don't get resolved as you'd expect? I don't have any ideas offhand, you could try looking at disassembly of the generated code to see if a frame pointer is indeed maintained (generally I'd expect there to be a "push %rbp" as the first instruction of a function symbol, and "pop %rbp" before returning). For instance: https://rust.godbolt.org/z/WM7xP83WK