• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1// Flags: --expose-gc --no-warnings
2'use strict';
3
4const common = require('../common');
5
6try {
7  require('trace_events');
8} catch {
9  common.skip('missing trace events');
10}
11
12common.skipIfWorker(); // https://github.com/nodejs/node/issues/22767
13
14const assert = require('assert');
15const cp = require('child_process');
16const path = require('path');
17const fs = require('fs');
18const tmpdir = require('../common/tmpdir');
19const {
20  createTracing,
21  getEnabledCategories
22} = require('trace_events');
23
24function getEnabledCategoriesFromCommandLine() {
25  const indexOfCatFlag = process.execArgv.indexOf('--trace-event-categories');
26  if (indexOfCatFlag === -1) {
27    return undefined;
28  }
29  return process.execArgv[indexOfCatFlag + 1];
30}
31
32const isChild = process.argv[2] === 'child';
33const enabledCategories = getEnabledCategoriesFromCommandLine();
34
35assert.strictEqual(getEnabledCategories(), enabledCategories);
36[1, 'foo', true, false, null, undefined].forEach((i) => {
37  assert.throws(() => createTracing(i), {
38    code: 'ERR_INVALID_ARG_TYPE',
39    name: 'TypeError'
40  });
41  assert.throws(() => createTracing({ categories: i }), {
42    code: 'ERR_INVALID_ARG_TYPE',
43    name: 'TypeError'
44  });
45});
46
47assert.throws(
48  () => createTracing({ categories: [] }),
49  {
50    code: 'ERR_TRACE_EVENTS_CATEGORY_REQUIRED',
51    name: 'TypeError'
52  }
53);
54
55const tracing = createTracing({ categories: [ 'node.perf' ] });
56
57assert.strictEqual(tracing.categories, 'node.perf');
58assert.strictEqual(tracing.enabled, false);
59
60assert.strictEqual(getEnabledCategories(), enabledCategories);
61tracing.enable();
62tracing.enable();  // Purposefully enable twice to test calling twice
63assert.strictEqual(tracing.enabled, true);
64
65assert.strictEqual(getEnabledCategories(),
66                   [
67                     ...[enabledCategories].filter((_) => !!_), 'node.perf'
68                   ].join(','));
69
70tracing.disable();
71assert.strictEqual(tracing.enabled, false);
72
73const tracing2 = createTracing({ categories: [ 'foo' ] });
74tracing2.enable();
75assert.strictEqual(getEnabledCategories(), 'foo');
76
77tracing2.disable();
78tracing2.disable();  // Purposefully disable twice to test calling twice
79assert.strictEqual(getEnabledCategories(), enabledCategories);
80
81if (isChild) {
82  tracing.enable();
83  const { performance } = require('perf_hooks');
84
85  // Will emit mark and measure trace events
86  performance.mark('A');
87  setTimeout(() => {
88    performance.mark('B');
89    performance.measure('A to B', 'A', 'B');
90  }, 1);
91
92  // Intentional non-op, part of the test
93  function f() {}
94  const ff = performance.timerify(f);
95  ff();  // Will emit a timerify trace event
96} else {
97
98  // Test that enabled tracing references do not get garbage collected
99  // until after they are disabled.
100  {
101    {
102      let tracing3 = createTracing({ categories: [ 'abc' ] });
103      tracing3.enable();
104      assert.strictEqual(getEnabledCategories(), 'abc');
105      tracing3 = undefined;
106    }
107    global.gc();
108    assert.strictEqual(getEnabledCategories(), 'abc');
109    // Not able to disable the thing after this point, however.
110  }
111
112  {
113    common.expectWarning(
114      'Warning',
115      'Possible trace_events memory leak detected. There are more than ' +
116      '10 enabled Tracing objects.');
117    for (let n = 0; n < 10; n++) {
118      const tracing = createTracing({ categories: [ `a${n}` ] });
119      tracing.enable();
120    }
121  }
122
123  testApiInChildProcess([], () => {
124    testApiInChildProcess(['--trace-event-categories', 'foo']);
125  });
126}
127
128function testApiInChildProcess(execArgs, cb) {
129  tmpdir.refresh();
130  // Save the current directory so we can chdir back to it later
131  const parentDir = process.cwd();
132  process.chdir(tmpdir.path);
133
134  const expectedMarks = ['A', 'B'];
135  const expectedBegins = [
136    { cat: 'node,node.perf,node.perf.timerify', name: 'f' },
137    { cat: 'node,node.perf,node.perf.usertiming', name: 'A to B' }
138  ];
139  const expectedEnds = [
140    { cat: 'node,node.perf,node.perf.timerify', name: 'f' },
141    { cat: 'node,node.perf,node.perf.usertiming', name: 'A to B' }
142  ];
143
144  const proc = cp.fork(__filename,
145                       ['child'],
146                       { execArgv: [ '--expose-gc', ...execArgs ] });
147
148  proc.once('exit', common.mustCall(() => {
149    const file = path.join(tmpdir.path, 'node_trace.1.log');
150
151    assert(fs.existsSync(file));
152    fs.readFile(file, common.mustCall((err, data) => {
153      assert.ifError(err);
154      const traces = JSON.parse(data.toString()).traceEvents
155        .filter((trace) => trace.cat !== '__metadata');
156      assert.strictEqual(traces.length,
157                         expectedMarks.length +
158                         expectedBegins.length +
159                         expectedEnds.length);
160
161      traces.forEach((trace) => {
162        assert.strictEqual(trace.pid, proc.pid);
163        switch (trace.ph) {
164          case 'R':
165            assert.strictEqual(trace.cat,
166                               'node,node.perf,node.perf.usertiming');
167            assert.strictEqual(trace.name,
168                               expectedMarks.shift());
169            break;
170          case 'b':
171            const expectedBegin = expectedBegins.shift();
172            assert.strictEqual(trace.cat, expectedBegin.cat);
173            assert.strictEqual(trace.name, expectedBegin.name);
174            break;
175          case 'e':
176            const expectedEnd = expectedEnds.shift();
177            assert.strictEqual(trace.cat, expectedEnd.cat);
178            assert.strictEqual(trace.name, expectedEnd.name);
179            break;
180          default:
181            assert.fail('Unexpected trace event phase');
182        }
183      });
184      process.chdir(parentDir);
185      cb && process.nextTick(cb);
186    }));
187  }));
188}
189