-
Notifications
You must be signed in to change notification settings - Fork 420
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
Chrome .cpuprofile
importer: Get profile start time from URL (Chrome DevTools UI format)
#4797
Chrome .cpuprofile
importer: Get profile start time from URL (Chrome DevTools UI format)
#4797
Conversation
…e DevTools UI format)
2eeb84d
to
1f92eb0
Compare
Codecov ReportAll modified and coverable lines are covered by tests ✅
Additional details and impacted files@@ Coverage Diff @@
## main #4797 +/- ##
=======================================
Coverage 88.62% 88.62%
=======================================
Files 308 308
Lines 28051 28059 +8
Branches 7596 7598 +2
=======================================
+ Hits 24859 24867 +8
Misses 2978 2978
Partials 214 214 ☔ View full report in Codecov by Sentry. 🚨 Try these New Features:
|
I guess Codecov has answered this question. |
697460e
to
444a45e
Compare
The profile conversion tests don't run a (headless) browser and so The test profile is actually an old profile produced using |
444a45e
to
77ebebf
Compare
Just checking: I see you were doing some changes recently, so can you please precise if it's ready for review now? Thanks :-) |
Yes, it's ready for review. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for your patience, while we were busy with other work.
I believe it is reasonable to pass "something" to the unserializing function.
We also need to pass the file name from retrieveProfileFromFile
in the same file, and also the file name from the file in a zip archive in viewProfileFromZip
in actions/zipped-profiles.js
.
My slight concern is that we do have startTime
and endTime
information in a .cpuprofile
file, but I'm not sure what value they are. Do you know? Do you have pointers to where these values are set or to some documentation about those?
I won't say I'm super happy about this. I wish we could use the existing startTime
and endTime
instead...
I left a few comments otherwise.
Tell me what you think!
src/profile-logic/import/chrome.js
Outdated
const timeStampRe = | ||
/(\d{4})(\d{2})(\d{2})T(\d{2})(\d{2})(\d{2}).*\.cpuprofile(?:$|\/|\?|#)/; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
const timeStampRe = | |
/(\d{4})(\d{2})(\d{2})T(\d{2})(\d{2})(\d{2}).*\.cpuprofile(?:$|\/|\?|#)/; | |
const timeStampRe = | |
/(\d{4})(\d{2})(\d{2})T(\d{2})(\d{2})(\d{2}).*\.cpuprofile\b/; |
In a regexp \b
means "a word boundary", which is exactly what you're looking for here.
Why do you have this .*
between the timestamp and .cpuprofile
?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In a regexp
\b
means "a word boundary", which is exactly what you're looking for here.
I beg to differ, (?:$|\/|\?|#)
implements the concept of "end of URL subdirectory" which is more strict than "end of word". In particular, \b
treats characters like %
and [
as a boundary which could result in profiles being accepted that do not have exactly the .cpuprofile
extension (for whatever deliberate reason).
That said, practically there probably isn't much point to be strict about this, and perhaps some people do put additional information on a filename after the file extension. I do prefer that a regex be as strict as possible though.
On the other hand, afaik Firefox Profiler doesn't specifically check for the .cpuprofile
extension, instead it looks at the profile's contents to determine profile type. So for consistency, the regex should just match a timestamp i.e. it should just be /(\d{4})(\d{2})(\d{2})T(\d{2})(\d{2})(\d{2})/
. What do you think?
Why do you have this
.*
between the timestamp and.cpuprofile
?
The basic filename produced (e.g. CPU-20230928T151126.cpuprofile
) is lacking in what the profile is all about, and the current regex already ignores everything before the timestamp. The .*
allows the regex to ignore everything after the timestamp before the extension. This is to cater for people who prefer to add identifying information after the timestamp rather than before it.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
3c62513 -- now I think it's best to be consistent with the rest of Firefox Profiler that doesn't specially treat the .cpuprofile
extension.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
251b59c matches on the last timestamp found, just in case someone sticks a timestamp on a folder. I wanted to use String.matchAll()
, but Flow 0.96.0 doesn't have a definition for it (!).
src/profile-logic/import/chrome.js
Outdated
(profileEvent.args.data.cpuProfile.endTime - | ||
profileEvent.args.data.cpuProfile.startTime) / |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
it's not clear to me that the difference will be in milliseconds. It seems to me this may be tenths of milliseconds, but I'm not so sure.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
emm not sure whether I'm getting you here -- it's known that cpuProfile.startTime
/ .endTime
is in microseconds, and one can convert both to milliseconds first before doing the difference (using / 1000
), but a / 1000 - b / 1000
is mathematically equivalent to (a - b) / 1000
via algebra, and the latter involves less operations.
If 1 startTime
/ endTime
tick is not actually 1 microsecond though, I suppose there has to be a way to change this assumption.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I would be amazed if there is a startTime
/ endTime
that actually exceeds Number.MAX_SAFE_INTEGER
(that would probably be a profile that has a lifespan longer than the average human), but since we require only millisecond precision, I suppose I should convert startTime
and endTime
to milliseconds first before doing the difference.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
0e626fd converted startTime
and endTime
to milliseconds first but was reverted because I got a test profilingEndTime
of 190.7039999961853 (due to floating point rounding error) instead of the correct 190.704.
src/profile-logic/import/chrome.js
Outdated
@@ -678,10 +680,28 @@ async function processTracingEvents( | |||
} | |||
|
|||
if (profileEvent.name === 'CpuProfile') { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I noticed there's a similar if condition above in the same function, where we do also set the threadInfo.lastSeenTime
information. I think it would be good to move all of this in the if block above (especially that it's closer to the Profile
block too). It would also be good to add a comment to remind the reader about the fact that CpuProfile
is added by us in wrapCpuProfileInEvent
because it took me 30min to remember that :D
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Hopefully will also get to this by early this week (or at least before this week ends).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I noticed there's a similar if condition above in the same function, where we do also set the
threadInfo.lastSeenTime
information. I think it would be good to move all of this in the if block above (especially that it's closer to theProfile
block too).
Done in f1108a4.
It would also be good to add a comment to remind the reader about the fact that
CpuProfile
is added by us inwrapCpuProfileInEvent
...
Done in 0ba0c39. The ts
field should matter?
src/profile-logic/import/chrome.js
Outdated
if (match) { | ||
const dateTimeString = `${match[1]}-${match[2]}-${match[3]}T${match[4]}:${match[5]}:${match[6]}`; | ||
const startTime = new Date(dateTimeString); | ||
profile.meta.startTime = startTime.getTime(); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Note that startTime
represent the moment the main thread started. So it's not great. But I don't see a better option with our current code.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
As long as the (adjustable) start time provided is reasonably close to the actual start time, I think it's going to be ok. Support for milliseconds could be added later on for more accuracy.
No worries, I'm under resourced too, sometimes terribly so, though partially it's because I don't really prefer focusing on just 1 project/language/topic unless I have to.
I'll get to this hopefully sometime early next week.
I actually did some spelunking in the Node V8 source code regarding this, and while I'm not 100% sure (largely because I don't have a Node build environment set up to test whether I'm actually looking at irrelevant duplicate code, and am not looking forward to building Node due to the build times involved), it appears that:
I didn't get much deeper than that, though it appears that on Windows
I'm not happy about this either, but short of persuading the V8 team to record as well the actual system clock time for |
…e subtracting" This reverts commit 0e626fd.
Done in 257485d, tested only manually though. |
Ok, it's ready for review. |
2982534
to
0ba0c39
Compare
Previously we were only doing this for CPUProfile profiles. But chrome adds this timestamp to all of its profile files including the Tracing files. See their source code here: https://source.chromium.org/chromium/chromium/src/+/main:third_party/devtools-frontend/src/front_end/panels/timeline/TimelinePanel.ts;l=1242-1251;drc=0cc387000bc7c9369fc34c2f2390d3cbc67f65ab So that's why this commit makes sure that we check the profile url for every type of chrome profiles, and not only for CPU profiles.
…n that We need the profilingStartTime for calculating the time range. That's why we can't simply put zero. But also we need to make sure that profiler frontend reports the correct time. Profiler calculates the recording start timestamp as `startTime + profilingStartTime`. So to be able to tell the user about the correct timestamp we read from the profile file name, we have to calculate the `startTime` like this: `timestamp from name - profilingStartTime`. This commit changes this to make sure that we always show the correct timestamp.
`getEmptyProfile` function already sets the `startTime` to zero.
Thanks for the PR @kazarmy! It looks great, I tweaked some things and pushed additional commits, mainly to make sure that it works well together with #5187. The things I've changed:
|
// timestamp is of profile save instead of profile start, but one can generate a | ||
// more accurate start timestamp through e.g. handling the Chrome DevTools | ||
// Protocol `Profiler.consoleProfileStarted` event. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't understand how "one" can do something here. Is that something we can do now, or something that could be done in the future?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think that's the event that's mentioned here: https://chromedevtools.github.io/devtools-protocol/1-2/Profiler/#event-consoleProfileStarted
It's an event that's a part of CDP.
I can't find the same event inside the profile data, so I'm not so sure how to do that. Maybe we can do that for chrome extension. But I'm not so sure, maybe @kazarmy had something else in mind while writing that.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think that's the event that's mentioned here: https://chromedevtools.github.io/devtools-protocol/1-2/Profiler/#event-consoleProfileStarted
Yes that's the event. I have code (from 11 months ago -- bit-rotted a bit but fortunately can still be made to run) that runs Chrome and attaches to it via https://github.com/cyrus-and/chrome-remote-interface.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ah I see. We also have this one btw: https://github.com/firefox-devtools/firefox-profiler-for-chrome We recently published it on the Chrome Web Store. That's why I was spending some time on improving the importer.
(It's not an alternative to the one you linked, just another way to visualize the data)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oh cool! I do prefer to programmatically start the Chrome profiler if possible, though I understand this might not be the best way to spend precious engineer time in a work environment.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks! 🎉 |
[Julien Wajsberg] Fix the network bars not being properly positioned in Chrome (#5209) [Nazım Can Altınova] Only show the NavigationStart in the timeline if it has innerWindowID (#5210) [Nisarg Jhaveri] Fix loading and error messages for /from-post-message (#5175) [Khairul Azhar Kasmiran] Chrome `.cpuprofile` importer: Get profile start time from URL (Chrome DevTools UI format) (#4797) [Khairul Azhar Kasmiran] Remove "Recording started" line from Profile Info if startTime is 0 (#5219) [Sean Kim] Add HTTP protocol version for a request in the profiler network tab (#5206) [Julien Wajsberg] Switch to a maintained fork of npm-run-all (#5221) [Nicolas Chevobbe] Adapt Tabs in High Contrast Mode (#5220) [Markus Stange] Fix test debugging in VS Code. (#5227) [Julien Wajsberg] Added appropriate null check to handle missing unified string optional values (#5192) And thanks to our localizers: de: Michael Köhler el: Jim Spentzos en-CA: chutten en-GB: Ian Neal es-CL: ravmn fy-NL: Fjoerfoks ia: Melo46 it: Michele Rodaro kab: ZiriSut nl: Mark Heijl pt-BR: Marcelo Ghelman ru: Valery Ledovskoy sv-SE: Andreas Pettersson tr: Grk zh-CN: Olvcpr423 zh-TW: Pin-guang Chen
This PR obtains a Chrome
.cpuprofile
start time from its URL / filename. The timestamp format currently supported is what is generated by the Chrome DevTools UI when one manually saves a profile from the Performance tab. The format, and the claim that the timestamp is generated on profile save, is based on https://chromium.googlesource.com/chromium/blink/+/refs/heads/main/Source/devtools/front_end/profiler/CPUProfileView.js#727.Change will manifest itself as an accurate timestamp here:
Questions:
window.location.href
. ShouldprofileUrl
be passed tounserializeProfileOfArbitraryFormat()
instead?(As a side note, the profile given to the
Profiler.consoleProfileFinished
event handler is slightly different from the profile generated when it is saved manually through the UI. No idea why.)┆Issue is synchronized with this Jira Task