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

C++ entry points not captured during profiling #29804

Closed
DullReferenceException opened this issue Oct 1, 2019 · 11 comments
Closed

C++ entry points not captured during profiling #29804

DullReferenceException opened this issue Oct 1, 2019 · 11 comments
Labels
macos Issues and PRs related to the macOS platform / OSX.

Comments

@DullReferenceException
Copy link

DullReferenceException commented Oct 1, 2019

  • Version: v12.11.1
  • Platform: Darwin 18.7.0 Darwin Kernel Version 18.7.0: Tue Aug 20 16:57:14 PDT 2019; root:xnu-4903.271.2~2/RELEASE_X86_64 x86_64

When capturing profiling information via node --prof then processing via node --prof-process, the C++ entry points section is blank, and just the node binary is shown in the bottom-up profile. Even in the summary, it shows 0 ticks for C++:

 [C++]:
   ticks  total  nonlib   name

 [Summary]:
   ticks  total  nonlib   name
    937    6.0%   88.1%  JavaScript
      0    0.0%    0.0%  C++
    403    2.6%   37.9%  GC
  14654   93.2%          Shared libraries
    126    0.8%          Unaccounted

I have seen more details before when using the profiling available in the CLI. While processing the profiling data, I see a lot of Code move event for unknown code messages output, so maybe this relates? node --cpu-prof also seems to omit these details.

@DullReferenceException
Copy link
Author

One possible clue: I do see C++ function names in the raw profiling logs; they're just not making their way to the --prof-process output.

@addaleax
Copy link
Member

addaleax commented Oct 1, 2019

I can’t reproduce this on x64 Linux. Can you figure out which Node.js versions this affects (in particular, whether v12.10.0 has the same issue), and whether this depends on the script you’re profiling?

@DullReferenceException
Copy link
Author

DullReferenceException commented Oct 1, 2019

It's happening for both node 10 and 12 for me. The versions I've tried are:

v10.15.3 - This used to work but stopped capturing C++ data for some reason
v10.16.3 - Tried to upgrade to latest LTS; same issue
v12.11.1 - Tried latest version, same issue

I suspect that there might be some environmental factor causing this issue, but I can't determine what that would be. I'm saying this because v10.15.3's profiling used to work fine.

One environmental change that occurred before this started happening is that I tried to enable dtrace inside of SIP using csrutil, and that's when this started happening. But after resetting SIP (csrutil reset) and even turning off SIP (csrutil disable), the problem persists, so I'm not 100% sure it relates to that. Maybe is a good hint for macOS experts?

@addaleax addaleax added the macos Issues and PRs related to the macOS platform / OSX. label Oct 1, 2019
@addaleax
Copy link
Member

addaleax commented Oct 1, 2019

@nodejs/platform-macos

@devnexen
Copy link
Contributor

devnexen commented Oct 1, 2019

tried with both 12.11.1 and current master branch and can't reproduce.
image

@Fishrock123
Copy link
Contributor

@devnexen Whats' your platform? i.e. what macos/darwin version?

@devnexen
Copy link
Contributor

devnexen commented Oct 1, 2019

18.7.0, last one

@DullReferenceException
Copy link
Author

DullReferenceException commented Oct 1, 2019

Would my --prof log file be helpful? It's 10MB or so.

@bnoordhuis
Copy link
Member

What do c++filt --version, nm --version and which c++filt nm print on your system? The log file processor calls out to them to look up and demangle C++ symbols.

@DullReferenceException
Copy link
Author

» c++filt --version                                                                                                                                      
GNU c++filt 070207 20070207
Copyright 2005 Free Software Foundation, Inc.
This program is free software; you may redistribute it under the terms of
the GNU General Public License.  This program has absolutely no warranty.

» nm --version                                                                                                                                           
Agreeing to the Xcode/iOS license requires admin privileges, please run “sudo xcodebuild -license” and then retry this command.

» which c++filt nm                                                                                                                                       
/usr/bin/c++filt
/usr/bin/nm

Maybe that second message is what's mucking things up. Trying again after accepting the license...

@DullReferenceException
Copy link
Author

Amazing, that was it! So perhaps an upgrade occurred and a new agreement requirement was injected without my knowledge.

Would there be a way for the profiler to notify users like me when this sort of thing occurs?

bnoordhuis added a commit to bnoordhuis/io.js that referenced this issue Oct 3, 2019
`node --prof-process` on macOS calls out to nm(1) to look up C++
symbols. If Xcode hasn't been properly installed or its license
hasn't been accepted yet, it prints out an error and exits.

Before this commit, that error was swallowed and the output of
the tick processor was not showing the C++ entry points.

This commit detects that error message and turns it into an
exception. No regression test because this particular condition
is hard to test for without going to extreme lengths to mock
the output of nm.

Fixes: nodejs#29804
@Trott Trott closed this as completed in 870eea3 Oct 6, 2019
BridgeAR pushed a commit that referenced this issue Oct 9, 2019
`node --prof-process` on macOS calls out to nm(1) to look up C++
symbols. If Xcode hasn't been properly installed or its license
hasn't been accepted yet, it prints out an error and exits.

Before this commit, that error was swallowed and the output of
the tick processor was not showing the C++ entry points.

This commit detects that error message and turns it into an
exception. No regression test because this particular condition
is hard to test for without going to extreme lengths to mock
the output of nm.

Fixes: #29804

PR-URL: #29830
Reviewed-By: David Carlier <[email protected]>
Reviewed-By: Colin Ihrig <[email protected]>
Reviewed-By: Ruben Bridgewater <[email protected]>
Reviewed-By: Minwoo Jung <[email protected]>
Reviewed-By: James M Snell <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
macos Issues and PRs related to the macOS platform / OSX.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants