Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add hermes-specific support for the trace event format #458

Merged
merged 5 commits into from
Dec 26, 2023

Conversation

zacharyfmarion
Copy link
Contributor

@zacharyfmarion zacharyfmarion commented Dec 26, 2023

Profiles that are transformed into the hermes trace event format are guaranteed to have specific arguments that supply metadata that is useful for debugging - namely the filename, line + col number that the function call originated from, with sourcemaps applied. This PR adds specific support for this information to the trace event importer. This means that we can have the Frame name be just the name of the function, since we know all the information we want to be displayed in the UI is captured in the frame info, which makes the traces cleaner to look at.

Before After
Screenshot 2023-12-26 at 2 40 01 PM Screenshot 2023-12-26 at 2 39 13 PM
Screenshot 2023-12-26 at 2 41 03 PM Screenshot 2023-12-26 at 2 41 29 PM

@coveralls
Copy link

coveralls commented Dec 26, 2023

Coverage Status

coverage: 43.517% (+0.1%) from 43.39%
when pulling a8aabb2 on zacharyfmarion:zac/hermes-specfic-changes
into 88f4fe6 on jlfwong:main.

@@ -48,12 +48,30 @@ interface TraceEvent {
cat?: string

// Any arguments provided for the event. Some of the event types have required argument fields, otherwise, you can put any information you wish in here. The arguments are displayed in Trace Viewer when you view an event in the analysis section.
args: any
args?: any
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Based on the spec this is not a required field for some event types, so marked it as optional. Happy to change back if this was intentional

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems fine

Copy link
Owner

@jlfwong jlfwong left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cool! High level looks good. A few minor requests inline, and then more generally please change all of the isHermesProfile arguments to be enum args instead of an ExporterSource with current values of UNKNOWN or HERMES. That way this will extend well if we want to specialize for other trace events types in the future, and also makes call-sites more self-documenting

@@ -669,6 +739,8 @@ export function importTraceEvents(rawProfile: Trace): ProfileGroup {
return sampleListToProfileGroup(rawProfile)
} else if (isTraceEventObject(rawProfile)) {
return eventListToProfileGroup(rawProfile.traceEvents)
} else if (isHermesTraceEventList(rawProfile)) {
return eventListToProfileGroup(rawProfile, true)
Copy link
Owner

@jlfwong jlfwong Dec 26, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As much as possible, I like to use enums rather than bare boolean arguments because it makes it clearer what's going on at the call-site. The true here isn't self documenting, but if this was e.g. return eventListToProfileGroup(rawProfile, ExportSource.HERMES) it would be really clear

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

makes sense - generally I just make any function that takes in more than one obvious parameter take in an object so the meaning of every param is clear at the callsite, but I saw that it isn't a pattern in the codebase. Using an enum is super readable, will do that

function isHermesTraceEventList(maybeEventList: any): maybeEventList is HermesTraceEvent[] {
if (!isTraceEventList(maybeEventList)) return false

return maybeEventList.every(el => isHermesTraceEvent(el.args))
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For the sake of hermes profile import speed, it's IMO fine to just check the first event. Otherwise this seems like it might be needlessly slow.

Comment on lines 690 to 699
const requiredProperties: Array<keyof HermesTraceEventArgs> = [
'line',
'column',
'name',
'category',
'url',
'params',
'allocatedCategory',
'allocatedName',
]
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Browsers probably optimize this anyway, but just for sanity, let's move this array outside of the call-stack. This seems like it would fit well as a constant directly below HermesTraceEventArgs as heremesTraceEventRequiredProperties

@zacharyfmarion
Copy link
Contributor Author

@jlfwong thanks for the feedback, pushed up some fixes!

// We just check the first element to avoid iterating over all trace events,
// and asumme that if the first one is formatted like a hermes profile then
// all events will be
return isHermesTraceEvent(maybeEventList[0].args)
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[0]?.args please!

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nevermind, this is guarded in isTraceEventList

@jlfwong jlfwong merged commit 4feb1e5 into jlfwong:main Dec 26, 2023
6 checks passed
@jlfwong
Copy link
Owner

jlfwong commented Dec 26, 2023

Amazing!

If you write a markdown description (just in a comment here is fine) for React Native profiling, then I'll copy that into the wiki and update the README to link to it to indicate there's specific support for React Native via Hermes.

Here's an example of such a page: https://github.com/jlfwong/speedscope/wiki/Importing-from-pprof-(go)

@zacharyfmarion
Copy link
Contributor Author

zacharyfmarion commented Dec 27, 2023

Importing from Hermes

Hermes is a javascript engine developed by facebook for use in react-native applications. For the most up-to-date instructions on how to take a profile, see Profiling with Hermes.

Profiling in Development Mode

To record a sampling profiler from the Dev Menu:

  1. Navigate to your running Metro server terminal.
  2. Press d to open the Dev Menu.
  3. Select Enable Sampling Profiler.
Screenshot 2023-12-27 at 8 51 15 AM
  1. Execute your JavaScript by in your app (press buttons, etc.)
  2. Open the Dev Menu by pressing d again.
  3. Select Enable Sampling Profiler again (this is currently a bug and might correctly say disable in the future) to stop recording and save the sampling profiler.

A toast will show the location where the sampling profiler has been saved, usually in /data/user/0/com.appName/cache/*.cpuprofile

You can then extract the profile from your emulator / device using the following command:

npx react-native@latest profile-hermes [destinationDir]

To view, drag and drop the profile from destinationDir into Speedscope.

Profiling in Release Mode

To profile hermes in a release build of your app, you can use the react-native-release-profiler npm package:

yarn add react-native-release-profiler
cd ios && pod install
  1. Build your app in release mode
  2. Start a profiling session:
import { startProfiling } from 'react-native-release-profiler'

startProfiling()
  1. Stop the profiling session:
import { stopProfiling } from 'react-native-release-profiler'

// `true` to save the trace to the phone's downloads folder, `false` otherwise
const path = await stopProfiling(true)
  1. Download and process the performance trace from your phone to your PC:
  • On Android:

First find your app id. It should look something like com.mypackage and be visible in app/build.gradle in the defaultConfig section:

android {
    defaultConfig {
        applicationId "com.profilern" // <-- This one!
        // ...
    }
}

Then run:

npx react-native-release-profiler --fromDownload --appId <your appId>
  • On iOS:
npx react-native-release-profiler --local <path to profile>

To view, drag and drop the profile saved in your current working directory into Spedscope. It should be transformed with sourcemaps!

@zacharyfmarion
Copy link
Contributor Author

@jlfwong took a pass at some docs ^. Profiling in release mode is something that Margelo recently worked one while contracting for my company, so honestly these are probably the most up-to-date / complete docs that exist anywhere right now.

@jlfwong
Copy link
Owner

jlfwong commented Dec 27, 2023

@zacharyfmarion Great! Added to the wiki, and updated the README.

Whenever you'd like to do an awareness push on Twitter or LinkedIn or wherever, let me know and I'll help signal boost.

sransara added a commit to sransara/speedscope that referenced this pull request Jul 13, 2024
commit d69f3d0
Author: Tom Levy <tomlevy93@gmail.com>
Date:   Tue Apr 16 06:50:13 2024 +1200

    Fix bug where import after error continues failing (jlfwong#463)

    Steps to reproduce:
    1. Open https://www.speedscope.app/
    2. Try to import an invalid file such as [invalid.json](https://github.com/jlfwong/speedscope/files/14167326/invalid.json). The page says "Something went wrong. Check the JS console for more details."
    3. Now try to import a valid file such as [simple.json](https://github.com/jlfwong/speedscope/files/14167335/simple.json). The page says "Something went wrong. Check the JS console for more details." even though this second file is valid.

    Explanation of the fix (copied from the commit message):
    > We need to clear the error flag, otherwise once there is an error and we display "Something went wrong" we will keep displaying that forever even when the user imports a valid file.

commit 25f671e
Author: Timo Tijhof <krinkle@fastmail.com>
Date:   Mon Apr 15 19:45:12 2024 +0100

    Bundle the font (jlfwong#472)

    For performance, offline support and privacy.

    Continues from jlfwong#412

commit 0121cf9
Author: Tom Levy <tomlevy93@gmail.com>
Date:   Tue Feb 6 07:58:18 2024 +1300

    Clarify specification of startValue in speedscope file format (jlfwong#464)

    The previous description ("event values will be relative to this
    startValue") was ambiguous.

    Suppose the profile starts at wall time 1000ms and the first event is
    at wall time 1003ms.

    The intention is that startValue should be set to 1000 and the "at"
    value of the event should be set to 1003. The viewer's time axis will
    start at 0ms and the first event will be displayed at 3ms.

    But the previous description could be incorrectly interpreted as
    saying that the "at" value of the first event should be set to 3 (the
    time relative to startValue, as opposed to the absolute wall time).

    Clarify that "relative" is referring to how the viewer displays the
    data, not about which values to store in the file.

commit 68fd88c
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Fri Jan 12 09:57:30 2024 -0800

    1.20.0

commit a6d7001
Author: Zachary Marion <zacharyfmarion@users.noreply.github.com>
Date:   Wed Jan 3 13:04:22 2024 -0800

    Partition based on samples instead of traceEvents when importing a sample-based chrome trace (jlfwong#460)

    In the existing code, if `traceEvents` did not have any importable events, the profile would be marked as empty. This was a bug, as the dev Hermes profiles I was testing with had one X event which made the code work. However we do not need to guarantee (and the spec doesn't seem to) any traceEvents being present as long as we have samples and stack frames.

    When I tested a production profile taken from Hermes it did not have any importable events, just a metadata event with a thread name. This PR updates the implementation to iterate over partitioned samples instead of traceEvents so we construct profiles for all thread + process pairs referenced in the samples array.

    | Before | After |
    | --- | ----- |
    | <img width="1454" alt="Screenshot 2024-01-03 at 9 58 56 AM" src="https://github.com/jlfwong/speedscope/assets/9957046/78c098a7-b374-4492-ad13-9ca79afdb40c"> | <img width="1450" alt="Screenshot 2024-01-03 at 9 58 17 AM" src="https://github.com/jlfwong/speedscope/assets/9957046/d2d5e82b-fa3e-43db-bf8a-e8c3b84cd13a"> |

commit a3c0b15
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Wed Dec 27 23:57:14 2023 -0500

    1.19.0

commit e9a17d5
Author: Zachary Marion <zacharyfmarion@users.noreply.github.com>
Date:   Wed Dec 27 23:56:27 2023 -0500

    Improve hermes profile frame keys to better group frames (jlfwong#459)

    Because all args are serialized in the key for hermes profiles, frames were not properly getting grouped since the "parent" property was different. This PR ensures that the frame key is properly constructed from the function name, file name, line + column number.

    | Before | After |
    | ----- | ----- |
    | <img width="1727" alt="Screenshot 2023-12-27 at 2 25 32 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/4ec04653-5a80-4f34-9506-48e0eb415983"> | <img width="1728" alt="Screenshot 2023-12-27 at 2 26 02 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/c3edc447-e8ad-4757-8576-cbb8c27eafe3"> |
    | <img width="1720" alt="Screenshot 2023-12-27 at 2 13 37 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/10194aba-8f26-48ca-bf15-06917b44ea99"> | <img width="1728" alt="Screenshot 2023-12-27 at 2 14 20 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/75c32401-1705-4b23-b71a-5f0a720160dd"> |

commit 3f3da22
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Wed Dec 27 10:48:07 2023 -0500

    Update README.md

    - Add link to Hermes import instructions
    - Re-order import sources higher in the list
    - Update first line

commit bea0ef6
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Tue Dec 26 17:12:59 2023 -0500

    1.18.0

commit 4feb1e5
Author: Zachary Marion <zacharyfmarion@users.noreply.github.com>
Date:   Tue Dec 26 17:00:18 2023 -0500

    Add hermes-specific support for the trace event format (jlfwong#458)

    Profiles that are transformed into the hermes trace event format are guaranteed to have specific arguments that supply metadata that is useful for debugging - namely the filename, line + col number that the function call originated from, with sourcemaps applied. This PR adds specific support for this information to the trace event importer. This means that we can have the Frame name be just the name of the function, since we know all the information we want to be displayed in the UI is captured in the frame info, which makes the traces cleaner to look at.

    | Before | After |
    |-----|-----|
    | <img width="1728" alt="Screenshot 2023-12-26 at 2 40 01 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/f9dff608-5df3-4098-b1f8-91a69185d906"> | <img width="1726" alt="Screenshot 2023-12-26 at 2 39 13 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/b8ff360e-a316-4bef-8ebc-620c9ff1a998"> |
    | <img width="1728" alt="Screenshot 2023-12-26 at 2 41 03 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/127a49b5-458e-4ac8-934a-202e565cb20f"> | <img width="1728" alt="Screenshot 2023-12-26 at 2 41 29 PM" src="https://github.com/jlfwong/speedscope/assets/9957046/ebb285ce-6b33-4535-8e45-b9ada4e4d97f"> |

commit 88f4fe6
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Mon Dec 25 22:52:46 2023 -0500

    Update README-ADMINS.md with npm login instructions (jlfwong#457)

commit 60f1812
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Mon Dec 25 22:40:40 2023 -0500

    1.17.0

commit 1717fec
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Mon Dec 25 22:37:45 2023 -0500

    Upgrade prettier, update prettier & react-hooks eslint plugins (jlfwong#456)

    Re-ran prettier with latest version

commit c296f53
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Mon Dec 25 22:23:33 2023 -0500

    Upgrade typescript & eslint to latest, fix resulting errors (jlfwong#455)

    Also updated the ci.yml node test versions to 18.x and 20.x, given current support: https://endoflife.date/nodejs

commit 8e0fa58
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Mon Dec 25 21:22:56 2023 -0500

    Re-enable eslint prettier rule after being accidentally disabled for 3 years (jlfwong#454)

    It looks like in jlfwong#267 (which was 3 years ago!), I accidentally disabled prettier linting altogether 😱

    https://github.com/jlfwong/speedscope/pull/267/files#diff-e2954b558f2aa82baff0e30964490d12942e0e251c1aa56c3294de6ec67b7cf5

    There's no comment in that PR about this being an intentional thing, so I have to assume this was a dumb mistake.

commit b214804
Author: Zachary Marion <zacharyfmarion@users.noreply.github.com>
Date:   Mon Dec 25 21:11:45 2023 -0500

    Support the chrome JSON trace format (allows viewing of hermes traces) (jlfwong#453)

commit dfd3a0d
Author: Zachary Marion <zacharyfmarion@users.noreply.github.com>
Date:   Sat Dec 16 00:27:03 2023 -0800

    Fix bug in selectQueueToTakeFromNext for trace profiles (jlfwong#450)

    I have been taking a lot of profiles using the Hermes profiler, but I noticed that they sometimes to not show up properly. After debugging what exactly was going on, I realized it was because the logic in `selectQueueToTakeFromNext` only checks for name, instead of the key for the event. I had a bunch of events with the name `anonymous` that were getting improperly exited before they should have been due to this logic.

    This fix makes the code more robust if there are added "args" which differentiate an event from another (as is the case in Hermes profiles), however it would still be an issue if they key just defaults to the name.

    Example profile before:

    <img width="1728" alt="Screenshot 2023-12-15 at 12 54 04 AM" src="https://github.com/jlfwong/speedscope/assets/9957046/345f556e-f944-40f1-b59c-748133acb950">

    What it should look like (in Perfetto):
    <img width="1051" alt="Screenshot 2023-12-15 at 8 51 38 AM" src="https://github.com/jlfwong/speedscope/assets/9957046/7473cdf8-95f1-49de-a0c7-ef4ac081ff85">

    After the fix:

    <img width="1728" alt="Screenshot 2023-12-15 at 12 54 29 AM" src="https://github.com/jlfwong/speedscope/assets/9957046/56b0870a-538b-4916-acc8-de2b7dfd78eb">

commit ac4a015
Author: Jamie Wong <jamie.lf.wong@gmail.com>
Date:   Thu Dec 7 18:43:47 2023 -0800

    Add bounds checking for sampleTypeIndex (jlfwong#449)

    Wow this was surprising. As reported in jlfwong#448, the `simple.speedscope.json` file failed import. This was surprising to me because there's a test that covers that file to ensure it imports correctly.

    The file provided in jlfwong#448, however, is from a version of speedscope from 5 years ago before the file had been pretty printed. It turns out that when this *particular* file is not pretty-printed, it's a schematically valid pprof profile.

    The fix is to do some bounds checks and return null. After the change, the file imports as you'd expect after realizing its not actually a valid pprof profile.

    Fixes jlfwong#448
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants