uftrace for deno

The deno is a secure JavaScript and TypeScript runtime written in Rust.

1. Download deno

$ git clone --recurse-submodules https://github.com/denoland/deno.git
$ cd deno

2. Install Rust

Make sure export PATH="$HOME/.cargo/bin:$PATH" is added to your environment variables.

$ curl https://sh.rustup.rs/ -sSf | sh
$ source $HOME/.cargo/env

3. Install & set nightly as default compiler

Nightly compiler is required for using -Z flag options.

$ rustup install nightly
$ rustup default nightly

4. Configure and build deno with uftrace

$ export RUSTFLAGS="-Z instrument-mcount"
$ cargo build

5. Check the generated binary

$ nm ./target/debug/deno | grep mcount
                 U mcount@@GLIBC_2.2.5

6. Get demangled version of Rust symbol names

More readable calling convention is needed to trace a specific function. rustfilt could pipe to stdout using grep or less.

$ cargo install rustfilt
$ nm ./target/debug/rustpython | rustfilt

7. Run deno interpreter with uftrace

$ uftrace record ./target/debug/deno run cli/tests/002_hello.ts
$ uftrace replay -t 100ms -F ^deno -F ^tokio
# DURATION     TID     FUNCTION
            [ 14101] | deno::main() {
            [ 14101] |   deno::tokio_util::run_basic() {
            [ 14101] |     tokio::runtime::Runtime::block_on() {
            [ 14101] |       tokio::runtime::handle::Handle::enter() {
            [ 14101] |         tokio::runtime::context::enter() {
            [ 14101] |           tokio::runtime::Runtime::block_on::_{{closure}}() {
            [ 14101] |             tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on() {
            [ 14101] |               tokio::runtime::basic_scheduler::enter() {
            [ 14101] |                 tokio::macros::scoped_tls::ScopedKey<T>::set() {
            [ 14101] |                   tokio::runtime::basic_scheduler::enter::_{{closure}}() {
            [ 14101] |                     tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::_{{closure}}() {
            [ 14101] |                       std::thread::local::LocalKey<T>::with() {
            [ 14101] |                         std::thread::local::LocalKey<T>::try_with() {
            [ 14101] |                           tokio::coop::with_budget::_{{closure}}() {
            [ 14101] |                             tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::_{{closure}}::_{{closure}}() {
            [ 14101] |                               _<core..pin..Pin<P> as core..future..future..Future>::poll() {
            [ 14101] |                                 _<core..future..from_generator..GenFuture<T> as core..future..future..Future>::poll() {
            [ 14101] |                                   deno::run_command::_{{closure}}() {
 113.479 ms [ 14101] |                                     deno::worker::MainWorker::create();
 190.676 ms [ 14101] |                                   } /* deno::run_command::_{{closure}} */
 190.683 ms [ 14101] |                                 } /* _<core..future..from_generator..GenFuture<T> as core..future..future..Future>::poll */
 190.684 ms [ 14101] |                               } /* _<core..pin..Pin<P> as core..future..future..Future>::poll */
 190.690 ms [ 14101] |                             } /* tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::_{{closure}}::_{{closure}} */
 190.697 ms [ 14101] |                           } /* tokio::coop::with_budget::_{{closure}} */
 190.703 ms [ 14101] |                         } /* std::thread::local::LocalKey<T>::try_with */
 190.704 ms [ 14101] |                       } /* std::thread::local::LocalKey<T>::with */
 190.736 ms [ 14101] |                     } /* tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::_{{closure}} */
 190.737 ms [ 14101] |                   } /* tokio::runtime::basic_scheduler::enter::_{{closure}} */
 190.755 ms [ 14101] |                 } /* tokio::macros::scoped_tls::ScopedKey<T>::set */
 190.772 ms [ 14101] |               } /* tokio::runtime::basic_scheduler::enter */
 190.773 ms [ 14101] |             } /* tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on */
 190.774 ms [ 14101] |           } /* tokio::runtime::Runtime::block_on::_{{closure}} */
 190.832 ms [ 14101] |         } /* tokio::runtime::context::enter */
 190.842 ms [ 14101] |       } /* tokio::runtime::handle::Handle::enter */
 190.842 ms [ 14101] |     } /* tokio::runtime::Runtime::block_on */
 192.079 ms [ 14101] |   } /* deno::tokio_util::run_basic */
 225.965 ms [ 14101] | } /* deno::main */

8. Generate chrome dump output

# record
$ uftrace record -t 10us ./target/debug/deno run cli/tests/002_hello.ts
Hello World

# dump in json format
$ uftrace dump --chrome > deno.json

# convert json to html
$ trace2html deno.json
deno.html

9. Visualized trace output of deno

• chrome: https://uftrace.github.io/dump/deno.html
• flame-graph: https://uftrace.github.io/dump/deno.svg