tracing: prevent race conditions during shutdown #21335

eugeneo · 2018-06-14T23:24:49Z

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
commit message follows commit guidelines

nodejs-github-bot · 2018-06-14T23:24:50Z

@eugeneo build started: https://ci.nodejs.org/blue/organizations/jenkins/node-test-pull-request-lite-pipeline/detail/node-test-pull-request-lite-pipeline/68/pipeline

ofrobots · 2018-06-14T23:30:16Z

/cc @nodejs/trace-events

ofrobots · 2018-06-14T23:31:51Z

It would be good to add the failing test case as well.

jasnell · 2018-06-14T23:32:48Z

src/tracing/agent.cc

@@ -66,16 +70,15 @@ void Agent::Start() {
  started_ = true;
 }

-Agent::ClientHandle Agent::AddClient(const std::set<std::string>& categories,
-                                     std::unique_ptr<AsyncTraceWriter> writer) {
+std::unique_ptr<ClientHandle> Agent::AddClient(


~~nit: need two spaces at the start here. looks like it's only one?~~~

Sigh... nevermind... misread the diff lol...sigh.

jasnell · 2018-06-14T23:35:47Z

main change looks good, test case would make it better.

ofrobots · 2018-06-15T00:12:48Z

src/tracing/agent.cc

+}
+
+void AgentHandle::AppendTraceEvent(TraceObject* trace_event) {
+  Mutex::ScopedLock scoped_lock(mutex_);


Can we benchmark the impact of this?

bnoordhuis

Left some comments. It's not entirely clear to me how this fixes #21383.

bnoordhuis · 2018-06-18T21:29:03Z

src/tracing/agent.cc

+void AgentHandle::Disconnect(int client) {
+  // This is supposed to be only callable from a main thread, same as Reset
+  // This code needs to be updated to enforce that.
+  if (agent_ != nullptr)


Shouldn't this method take out the lock first?

I cannot add lock without significant rework (which would delay this PR) because node::Mutex is not reentrant... Currently this is only called on the isolate thread (i.e. it will be be correct for webworkers) so it is correct without the lock... But it is not obvious

Okay, can you update the comment and maybe make a bit more imperative? "Is supposed to" isn't strong enough.

bnoordhuis · 2018-06-18T21:29:37Z

src/tracing/agent.h

-  static ClientHandle EmptyClientHandle() {
-    return ClientHandle(nullptr, DisconnectClient);
+ private:
+  node::Mutex mutex_;


Not necessary to qualify, right?

bnoordhuis · 2018-06-18T21:29:56Z

src/tracing/agent.h

+  ClientHandle(const ClientHandle&) = delete;
+  ClientHandle& operator=(const ClientHandle&) = delete;
+  ~ClientHandle();
+  int id() {


int id() const?

bnoordhuis · 2018-06-18T21:30:12Z

src/tracing/agent.h

+
+ private:
+  std::shared_ptr<AgentHandle> agent_;
+  int id_;


And maybe make this const as well?

bnoordhuis · 2018-06-19T10:05:45Z

src/tracing/agent.cc

+void AgentHandle::Disconnect(int client) {
+  // This is supposed to be only callable from a main thread, same as Reset
+  // This code needs to be updated to enforce that.
+  if (agent_ != nullptr)


Okay, can you update the comment and maybe make a bit more imperative? "Is supposed to" isn't strong enough.

bnoordhuis · 2018-06-19T10:06:41Z

src/tracing/agent.h

-  using ClientHandle = std::unique_ptr<std::pair<Agent*, int>,
-                                       void (*)(std::pair<Agent*, int>*)>;
+  explicit AgentHandle(Agent*);
+  void Reset();


Maybe call Reset() from the destructor so you don't have to call it explicitly in Agent::~Agent()?

Here, AgentHandle is supposed to be a weak pointer - it allows accessing the tracing agent but does not prevent its destruction. I had a naive implementation with shared_ptr/weak_ptr but the issue there is that it may cause Agent to be deleted on a wrong thread.

bnoordhuis · 2018-06-19T10:08:24Z

src/tracing/agent.h

-  // Resetting the pointer disconnects client
-  using ClientHandle = std::unique_ptr<std::pair<Agent*, int>,
-                                       void (*)(std::pair<Agent*, int>*)>;
+  explicit AgentHandle(Agent*);


Agent* agent and consider changing the data member to Agent* const agent_;

See comment above.

bnoordhuis · 2018-06-19T10:08:59Z

src/tracing/agent.h

+  ClientHandle& operator=(const ClientHandle&) = delete;
+  ~ClientHandle();
+  int id() const {
+    return id_;
  }


The style guide allows doing this on one line.

apapirovski · 2018-06-19T14:52:47Z

@matthiaskrgr Would you be able to test this patch against your build with AddressSanitizer and see if it fixes the issue? Thanks!

jasnell · 2018-06-21T15:43:51Z

src/tracing/agent.h


  // These 3 methods operate on a "default" client, e.g. the file writer
  void Enable(const std::string& categories);
  void Enable(const std::set<std::string>& categories);
  void Disable(const std::set<std::string>& categories);
  std::string GetEnabledCategories();

-  void AppendTraceEvent(TraceObject* trace_event);
+  // void AppendTraceEvent(TraceObject* trace_event);


Should this be removed rather than commented out?

I pushed a wrong version - this method is still in use...

PR-URL: #21335 Reviewed-By: James M Snell <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]>

eugeneo · 2018-06-21T15:57:47Z

CI: https://ci.nodejs.org/job/node-test-pull-request/15554/

eugeneo · 2018-06-21T16:51:17Z

Test failure needs to be debugged on Windows.

ofrobots · 2018-06-26T21:36:44Z

Test failure on windows is actually a crash:

12:38:43     AssertionError [ERR_ASSERTION]: Input A expected to strictly equal input B:
12:38:43     + expected - actual
12:38:43     
12:38:43     - 1
12:38:43     + 3221225477

3221225477 is 0xC0000005, an access violation on windows.

ofrobots · 2018-06-26T23:48:32Z

I have been unable to reproduce the crash on my windows machine so far.

ofrobots · 2018-06-27T05:29:34Z

New CI: https://ci.nodejs.org/job/node-test-pull-request/15642/. All green.

ofrobots · 2018-06-28T18:19:25Z

Second CI is green on windows as well: https://ci.nodejs.org/job/node-test-pull-request/15656/ and I cannot reproduce the crashes on windows.

ofrobots · 2018-06-28T18:22:23Z

Launched a stress of the single test on windows: https://ci.nodejs.org/job/node-stress-single-test/1929/

ofrobots · 2018-06-28T20:27:21Z

The stress test definitely shows crashes. @eugeneo

eugeneo · 2018-07-13T16:08:07Z

This will be reimplemented from scratch, current design cannot work.

eugeneo requested a review from ofrobots June 14, 2018 23:24

nodejs-github-bot added c++ Issues and PRs that require attention from people who are familiar with C++. lib / src Issues and PRs related to general changes in the lib or src directory. labels Jun 14, 2018

jasnell reviewed Jun 14, 2018

View reviewed changes

jasnell approved these changes Jun 14, 2018

View reviewed changes

ofrobots reviewed Jun 15, 2018

View reviewed changes

eugeneo mentioned this pull request Jun 18, 2018

make test: use after free: parallel/test-cli-node-options #21383

Open

bnoordhuis reviewed Jun 18, 2018

View reviewed changes

bnoordhuis approved these changes Jun 19, 2018

View reviewed changes

jasnell reviewed Jun 21, 2018

View reviewed changes

tracing: prevent race conditions during shutdown

a627bc1

PR-URL: #21335 Reviewed-By: James M Snell <[email protected]> Reviewed-By: Ben Noordhuis <[email protected]>

eugeneo added the wip Issues and PRs that are still a work in progress. label Jun 21, 2018

ofrobots added the trace_events Issues and PRs related to V8, Node.js core, and userspace code trace events. label Jun 26, 2018

ofrobots mentioned this pull request Jun 26, 2018

parallel/test-trace-events-api crash on Windows #20173

Closed

ofrobots mentioned this pull request Jun 28, 2018

src: trace_event: secondary storage for metadata #20900

Closed

3 tasks

eugeneo closed this Jul 13, 2018

eugeneo deleted the tracing-crash branch July 13, 2018 17:53

tracing: prevent race conditions during shutdown #21335

tracing: prevent race conditions during shutdown #21335

Conversation

eugeneo commented Jun 14, 2018

Checklist

nodejs-github-bot commented Jun 14, 2018

ofrobots commented Jun 14, 2018

ofrobots commented Jun 14, 2018

jasnell Jun 14, 2018 • edited Loading

Choose a reason for hiding this comment

jasnell commented Jun 14, 2018

Choose a reason for hiding this comment

bnoordhuis left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

apapirovski commented Jun 19, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

eugeneo commented Jun 21, 2018

eugeneo commented Jun 21, 2018

ofrobots commented Jun 26, 2018

ofrobots commented Jun 26, 2018

ofrobots commented Jun 27, 2018

ofrobots commented Jun 28, 2018

ofrobots commented Jun 28, 2018

ofrobots commented Jun 28, 2018

eugeneo commented Jul 13, 2018

jasnell Jun 14, 2018 •

edited

Loading