• 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                       {
147                         execArgv: [
148                           '--expose-gc',
149                           ...execArgs,
150                         ]
151                       });
152
153  proc.once('exit', common.mustCall(() => {
154    const file = path.join(tmpdir.path, 'node_trace.1.log');
155
156    assert(fs.existsSync(file));
157    fs.readFile(file, common.mustSucceed((data) => {
158      const traces = JSON.parse(data.toString()).traceEvents
159        .filter((trace) => trace.cat !== '__metadata');
160      assert.strictEqual(traces.length,
161                         expectedMarks.length +
162                         expectedBegins.length +
163                         expectedEnds.length);
164
165      traces.forEach((trace) => {
166        assert.strictEqual(trace.pid, proc.pid);
167        switch (trace.ph) {
168          case 'R':
169            assert.strictEqual(trace.cat,
170                               'node,node.perf,node.perf.usertiming');
171            assert.strictEqual(trace.name,
172                               expectedMarks.shift());
173            break;
174          case 'b':
175            const expectedBegin = expectedBegins.shift();
176            assert.strictEqual(trace.cat, expectedBegin.cat);
177            assert.strictEqual(trace.name, expectedBegin.name);
178            break;
179          case 'e':
180            const expectedEnd = expectedEnds.shift();
181            assert.strictEqual(trace.cat, expectedEnd.cat);
182            assert.strictEqual(trace.name, expectedEnd.name);
183            break;
184          default:
185            assert.fail('Unexpected trace event phase');
186        }
187      });
188      process.chdir(parentDir);
189      cb && process.nextTick(cb);
190    }));
191  }));
192}
193