loop,threadpool: trace events by jasnell · Pull Request #1815 · libuv/libuv

jasnell · 2018-04-23T21:14:17Z

This is an alternative take to #1764 that uses a more trace-events style API as suggested by @bnoordhuis.

void start_cb(const uv_trace_info_t* info, void* data) {
  switch (info->type) {
    case UV_TRACE_TICK:
    // ...
  }
}

void end_cb(const uv_trace_info_t* info, void* data) {
  switch (info->type) {
    case UV_TRACE_TICK:
    // ...
  }
}

uv_loop_trace_t loop_config;
loop_config.start_cb = start_cb;
loop_config.end_cb = end_cb;
loop_config.data = &loop;

uv_loop_configure(&loop, UV_LOOP_TRACE, &loop_config);

void threadpool_trace_cb(const uv_trace_info_t* info, void* data) {
  const uv_threadpool_trace_info_t* tp_info =
    (const uv_threadpool_trace_info_t*)info;
  // ...
}

uv_threadpool_trace_t tp_config;
loop_config.cb = threadpool_trace_cb;
loop_config.data = &loop;

uv_loop_configure(&loop, UV_THREADPOOL_TRACE, &tp_config);

This approach greatly simplifies the record keeping required in V8 and minimizes the possible ABI breakages that could occur. It would integrate quite well with V8 Trace Events in Node.js but would increase the record keeping necessary there to integrate with things like the Performance API (record keeping would still be minimal).

The UV_LOOP_TRACE and UV_THREADPOOL_TRACE configuration options are separate largely to keep internal tracking simple. Loop tracing is specific to individual loops, while the threadpool may have multiple listeners. Keeping them separate allows for greatly simplified tracking without internals getting muddy.

jasnell · 2018-06-01T19:57:34Z

Ping @bnoordhuis @cjihrig @evanlucas @saghul ... I'd like to close the loop on this soon, if at all possible. This is an alternate take on the ideas in #1764 that uses more of a trace-events style model (as suggested by @bnoordhuis)

jasnell · 2018-06-22T20:12:32Z

Ping again... I'd like to get this landed. This particular version does require an ABI change and would require libuv 2.0... however, it would be possible to set this particular version up so that changes to uv_loop_t are not necessary by introducing a new static callback that can be set with a separate API (e.g. uv_set_trace_callback(cb) where the first argument passed to cb is the uv_loop_t. Could potentially make things easier for supporting multiple event_loops/isolates now that Workers have landed in Node.js core.

jasnell · 2018-07-13T20:50:48Z

@cjihrig @evanlucas @saghul @bnoordhuis ... would it be possible to get some idea of when this may be looked at?

santigimeno

Also the loop_trace test is failing locally:

not ok 139 - loop_trace
# exit code 6
# Output from process `loop_trace`:
# Assertion failed in test/test-loop-trace.c on line 129: saw_start_event & (1 << UV_TRACE_POLL)

santigimeno · 2018-04-25T21:45:40Z

+#define START_SIZE 8
+static unsigned idle_max = 0;
+static unsigned idle_min = 2 * START_SIZE;
+static unsigned queued_max = 0;


No need to initialize static variables to zero

santigimeno · 2018-04-25T21:46:35Z

        'test-loop-close.c',
        'test-loop-stop.c',
        'test-loop-time.c',
+        'test-loop-trace.c',


test-threadpool-trace.c should be added too

santigimeno · 2018-07-28T12:03:28Z

    }

    test_result = run_test(task->task_name, benchmark_output, current);
+    fflush(stderr);


I'm not sure this change belongs here.

santigimeno · 2018-07-28T12:03:52Z

  uv_req_t* req;
  uv_req_t* first;
  uv_req_t* next;
+  size_t count = 0;


separate declaration from assignment

santigimeno · 2018-07-28T12:05:43Z

  QUEUE* q;
  QUEUE pq;
  uv__io_t* w;
+  size_t count = 0;


Style: separate declaration from assignment

santigimeno · 2018-07-28T14:15:30Z

+}
+
+void uv__trace_end(uv_loop_t* loop,
+                   const uv_trace_info_t* info) {


Style: this can go on 1 line only

santigimeno · 2018-07-28T14:20:28Z

@@ -0,0 +1,148 @@
+/* Copyright (c) 2014, Ben Noordhuis <info@bnoordhuis.nl>


Change the copyright to something like this.

santigimeno · 2018-07-28T14:20:45Z

+static size_t check_count = 0;
+static size_t idle_count = 0;
+static size_t prepare_count = 0;
+static size_t pending_count = 0;


No need to initialize static variables to zero.

santigimeno · 2018-07-28T17:00:15Z


-      if (timeout == 0)
+      if (timeout == 0) {
+        uv__trace_end(loop, (uv_trace_info_t*)&trace_info);


Maybe instead of adding the uv__trace_end() call on every return, add a label and use goto.

santigimeno · 2018-07-28T17:02:36Z

 enum {
-  UV_LOOP_BLOCK_SIGPROF = 1
+  UV_LOOP_BLOCK_SIGPROF = 1,
+  UV_LOOP_TRACE_NOTIFY = 2


I can't see this flag being used in the code.

look in unix/loop.c ... it's set as a loop->flags... purely informational right now.

jasnell · 2018-08-24T21:02:32Z

@santigimeno ... what platform are you testing on where it's failing locally? loop_trace is passing for me on Ubuntu so I'm not sure what's up.

santigimeno · 2018-09-01T11:29:32Z

what platform are you testing on where it's failing locally? loop_trace is passing for me on Ubuntu so I'm not sure what's up.

@jasnell on OS X. I'll try to look at it.

bnoordhuis

I've thought about this PR and I say let's not do this for now. Landing it very much complicates the thread pool redesign discussed in #1959. That's an important and long-standing issue.

What's more, if the pluggable thread pool approach goes through, which seems likely, the tracing functionality in libuv becomes obsolete. Node.js won't use it because it'll move to its own custom thread pool and other users are unlikely.

(Besides, such users can plug in their own thread pool with added instrumentation. To me that's a strictly superior option.)

jasnell · 2018-09-02T13:34:07Z

That seems to only impact the threadpool aspect of this, not the loop tracing.

davisjam · 2018-09-02T16:12:07Z

That seems to only impact the threadpool aspect of this, not the loop tracing.

I agree -- Node would still benefit from loop tracing. And I don't see a problem in supporting tracing in the default libuv threadpool, thus benefiting embedders who don't plug in their own TPs.

bnoordhuis · 2018-09-04T19:42:52Z

That seems to only impact the threadpool aspect of this, not the loop tracing.

@jasnell It reminds me of the dtrace/systemtap probes I removed in cb51400. Lots of infrastructure and maintenance for something that was ultimately of marginal value.

They traced event loop ticks too but at least they were zero cost when disabled. This PR on the other hand adds some ever-present overhead.

And since it targets master and is a pretty big diff, it'll be an ongoing merge conflict magnet as long as the v1.x branch is alive.

I'm not really convinced it's worth it for those two (three?) reasons. I just can't get excited about it. Maybe other maintainers feel differently.

And I don't see a problem in supporting tracing in the default libuv threadpool

@davisjam I'm sympathetic to that argument but I don't think anyone asked for thread pool tracing except Node.js + derivatives, and I expect that for them it's only a stop-gap measure.

I'm open to reconsidering it if other users do pop up, however. It would be good to get more feedback on the API anyhow.

pfreixes · 2019-02-07T11:07:38Z

Its a pity not having this PR, or at least the loop events, moving forward ..... what can we do ? or what is needed to justify the adoption of loop traces?

stale · 2019-08-10T01:51:39Z

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

jasnell mentioned this pull request Apr 23, 2018

loop,threadpool: collect statistics #1764

Closed

santigimeno requested changes Jul 28, 2018

View reviewed changes

santigimeno mentioned this pull request Jul 28, 2018

src: add uv_loop watcher_queue update apis #1921

Closed

jasnell added 3 commits August 24, 2018 13:40

loop: add loop trace events

93eac32

threadpool: add threadpool trace events

81ec486

docs: add docs for trace events

513e997

jasnell force-pushed the loop-stats-redo2 branch from b6e9f94 to 513e997 Compare August 24, 2018 20:40

[Squash] feedback

318b951

cjihrig mentioned this pull request Aug 29, 2018

Debugging guide and/or internal tracing for debugging purposes #1966

Closed

davisjam mentioned this pull request Aug 29, 2018

Libuv thread pool UV_THREADPOOL_SIZE in a node cluser setup nodejs/node#22468

Closed

bnoordhuis requested changes Sep 2, 2018

View reviewed changes

This was referenced Sep 19, 2018

Threadpool monitoring / metrics nodejs/node#22957

Closed

Incorporating metrics from the threadpool clinicjs/node-clinic#58

Open

stale Bot added the stale label Aug 10, 2019

stale Bot closed this Aug 17, 2019

		@@ -0,0 +1,148 @@
		/* Copyright (c) 2014, Ben Noordhuis <info@bnoordhuis.nl>

Conversation

jasnell commented Apr 23, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jasnell commented Jun 1, 2018

Uh oh!

jasnell commented Jun 22, 2018

Uh oh!

jasnell commented Jul 13, 2018

Uh oh!

santigimeno left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jasnell commented Aug 24, 2018

Uh oh!

santigimeno commented Sep 1, 2018

Uh oh!

bnoordhuis left a comment

Choose a reason for hiding this comment

Uh oh!

jasnell commented Sep 2, 2018

Uh oh!

davisjam commented Sep 2, 2018

Uh oh!

bnoordhuis commented Sep 4, 2018

Uh oh!

pfreixes commented Feb 7, 2019

Uh oh!

stale Bot commented Aug 10, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

jasnell commented Apr 23, 2018 •

edited

Loading