You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

442 lines
9.5 KiB

4 years ago
  1. const fs = require("fs");
  2. const path = require("path");
  3. const mkdirp = require("mkdirp");
  4. const { Tracer } = require("chrome-trace-event");
  5. const validateOptions = require("schema-utils");
  6. const schema = require("../../schemas/plugins/debug/ProfilingPlugin.json");
  7. /** @typedef {import("../../declarations/plugins/debug/ProfilingPlugin").ProfilingPluginOptions} ProfilingPluginOptions */
  8. let inspector = undefined;
  9. try {
  10. // eslint-disable-next-line node/no-unsupported-features/node-builtins
  11. inspector = require("inspector");
  12. } catch (e) {
  13. console.log("Unable to CPU profile in < node 8.0");
  14. }
  15. class Profiler {
  16. constructor(inspector) {
  17. this.session = undefined;
  18. this.inspector = inspector;
  19. }
  20. hasSession() {
  21. return this.session !== undefined;
  22. }
  23. startProfiling() {
  24. if (this.inspector === undefined) {
  25. return Promise.resolve();
  26. }
  27. try {
  28. this.session = new inspector.Session();
  29. this.session.connect();
  30. } catch (_) {
  31. this.session = undefined;
  32. return Promise.resolve();
  33. }
  34. return Promise.all([
  35. this.sendCommand("Profiler.setSamplingInterval", {
  36. interval: 100
  37. }),
  38. this.sendCommand("Profiler.enable"),
  39. this.sendCommand("Profiler.start")
  40. ]);
  41. }
  42. sendCommand(method, params) {
  43. if (this.hasSession()) {
  44. return new Promise((res, rej) => {
  45. return this.session.post(method, params, (err, params) => {
  46. if (err !== null) {
  47. rej(err);
  48. } else {
  49. res(params);
  50. }
  51. });
  52. });
  53. } else {
  54. return Promise.resolve();
  55. }
  56. }
  57. destroy() {
  58. if (this.hasSession()) {
  59. this.session.disconnect();
  60. }
  61. return Promise.resolve();
  62. }
  63. stopProfiling() {
  64. return this.sendCommand("Profiler.stop");
  65. }
  66. }
  67. /**
  68. * an object that wraps Tracer and Profiler with a counter
  69. * @typedef {Object} Trace
  70. * @property {Tracer} trace instance of Tracer
  71. * @property {number} counter Counter
  72. * @property {Profiler} profiler instance of Profiler
  73. * @property {Function} end the end function
  74. */
  75. /**
  76. * @param {string} outputPath The location where to write the log.
  77. * @returns {Trace} The trace object
  78. */
  79. const createTrace = outputPath => {
  80. const trace = new Tracer({
  81. noStream: true
  82. });
  83. const profiler = new Profiler(inspector);
  84. if (/\/|\\/.test(outputPath)) {
  85. const dirPath = path.dirname(outputPath);
  86. mkdirp.sync(dirPath);
  87. }
  88. const fsStream = fs.createWriteStream(outputPath);
  89. let counter = 0;
  90. trace.pipe(fsStream);
  91. // These are critical events that need to be inserted so that tools like
  92. // chrome dev tools can load the profile.
  93. trace.instantEvent({
  94. name: "TracingStartedInPage",
  95. id: ++counter,
  96. cat: ["disabled-by-default-devtools.timeline"],
  97. args: {
  98. data: {
  99. sessionId: "-1",
  100. page: "0xfff",
  101. frames: [
  102. {
  103. frame: "0xfff",
  104. url: "webpack",
  105. name: ""
  106. }
  107. ]
  108. }
  109. }
  110. });
  111. trace.instantEvent({
  112. name: "TracingStartedInBrowser",
  113. id: ++counter,
  114. cat: ["disabled-by-default-devtools.timeline"],
  115. args: {
  116. data: {
  117. sessionId: "-1"
  118. }
  119. }
  120. });
  121. return {
  122. trace,
  123. counter,
  124. profiler,
  125. end: callback => {
  126. // Wait until the write stream finishes.
  127. fsStream.on("finish", () => {
  128. callback();
  129. });
  130. // Tear down the readable trace stream.
  131. trace.push(null);
  132. }
  133. };
  134. };
  135. const pluginName = "ProfilingPlugin";
  136. class ProfilingPlugin {
  137. /**
  138. * @param {ProfilingPluginOptions=} opts options object
  139. */
  140. constructor(opts) {
  141. validateOptions(schema, opts || {}, "Profiling plugin");
  142. opts = opts || {};
  143. this.outputPath = opts.outputPath || "events.json";
  144. }
  145. apply(compiler) {
  146. const tracer = createTrace(this.outputPath);
  147. tracer.profiler.startProfiling();
  148. // Compiler Hooks
  149. Object.keys(compiler.hooks).forEach(hookName => {
  150. compiler.hooks[hookName].intercept(
  151. makeInterceptorFor("Compiler", tracer)(hookName)
  152. );
  153. });
  154. Object.keys(compiler.resolverFactory.hooks).forEach(hookName => {
  155. compiler.resolverFactory.hooks[hookName].intercept(
  156. makeInterceptorFor("Resolver", tracer)(hookName)
  157. );
  158. });
  159. compiler.hooks.compilation.tap(
  160. pluginName,
  161. (compilation, { normalModuleFactory, contextModuleFactory }) => {
  162. interceptAllHooksFor(compilation, tracer, "Compilation");
  163. interceptAllHooksFor(
  164. normalModuleFactory,
  165. tracer,
  166. "Normal Module Factory"
  167. );
  168. interceptAllHooksFor(
  169. contextModuleFactory,
  170. tracer,
  171. "Context Module Factory"
  172. );
  173. interceptAllParserHooks(normalModuleFactory, tracer);
  174. interceptTemplateInstancesFrom(compilation, tracer);
  175. }
  176. );
  177. // We need to write out the CPU profile when we are all done.
  178. compiler.hooks.done.tapAsync(
  179. {
  180. name: pluginName,
  181. stage: Infinity
  182. },
  183. (stats, callback) => {
  184. tracer.profiler.stopProfiling().then(parsedResults => {
  185. if (parsedResults === undefined) {
  186. tracer.profiler.destroy();
  187. tracer.trace.flush();
  188. tracer.end(callback);
  189. return;
  190. }
  191. const cpuStartTime = parsedResults.profile.startTime;
  192. const cpuEndTime = parsedResults.profile.endTime;
  193. tracer.trace.completeEvent({
  194. name: "TaskQueueManager::ProcessTaskFromWorkQueue",
  195. id: ++tracer.counter,
  196. cat: ["toplevel"],
  197. ts: cpuStartTime,
  198. args: {
  199. src_file: "../../ipc/ipc_moji_bootstrap.cc",
  200. src_func: "Accept"
  201. }
  202. });
  203. tracer.trace.completeEvent({
  204. name: "EvaluateScript",
  205. id: ++tracer.counter,
  206. cat: ["devtools.timeline"],
  207. ts: cpuStartTime,
  208. dur: cpuEndTime - cpuStartTime,
  209. args: {
  210. data: {
  211. url: "webpack",
  212. lineNumber: 1,
  213. columnNumber: 1,
  214. frame: "0xFFF"
  215. }
  216. }
  217. });
  218. tracer.trace.instantEvent({
  219. name: "CpuProfile",
  220. id: ++tracer.counter,
  221. cat: ["disabled-by-default-devtools.timeline"],
  222. ts: cpuEndTime,
  223. args: {
  224. data: {
  225. cpuProfile: parsedResults.profile
  226. }
  227. }
  228. });
  229. tracer.profiler.destroy();
  230. tracer.trace.flush();
  231. tracer.end(callback);
  232. });
  233. }
  234. );
  235. }
  236. }
  237. const interceptTemplateInstancesFrom = (compilation, tracer) => {
  238. const {
  239. mainTemplate,
  240. chunkTemplate,
  241. hotUpdateChunkTemplate,
  242. moduleTemplates
  243. } = compilation;
  244. const { javascript, webassembly } = moduleTemplates;
  245. [
  246. {
  247. instance: mainTemplate,
  248. name: "MainTemplate"
  249. },
  250. {
  251. instance: chunkTemplate,
  252. name: "ChunkTemplate"
  253. },
  254. {
  255. instance: hotUpdateChunkTemplate,
  256. name: "HotUpdateChunkTemplate"
  257. },
  258. {
  259. instance: javascript,
  260. name: "JavaScriptModuleTemplate"
  261. },
  262. {
  263. instance: webassembly,
  264. name: "WebAssemblyModuleTemplate"
  265. }
  266. ].forEach(templateObject => {
  267. Object.keys(templateObject.instance.hooks).forEach(hookName => {
  268. templateObject.instance.hooks[hookName].intercept(
  269. makeInterceptorFor(templateObject.name, tracer)(hookName)
  270. );
  271. });
  272. });
  273. };
  274. const interceptAllHooksFor = (instance, tracer, logLabel) => {
  275. if (Reflect.has(instance, "hooks")) {
  276. Object.keys(instance.hooks).forEach(hookName => {
  277. instance.hooks[hookName].intercept(
  278. makeInterceptorFor(logLabel, tracer)(hookName)
  279. );
  280. });
  281. }
  282. };
  283. const interceptAllParserHooks = (moduleFactory, tracer) => {
  284. const moduleTypes = [
  285. "javascript/auto",
  286. "javascript/dynamic",
  287. "javascript/esm",
  288. "json",
  289. "webassembly/experimental"
  290. ];
  291. moduleTypes.forEach(moduleType => {
  292. moduleFactory.hooks.parser
  293. .for(moduleType)
  294. .tap("ProfilingPlugin", (parser, parserOpts) => {
  295. interceptAllHooksFor(parser, tracer, "Parser");
  296. });
  297. });
  298. };
  299. const makeInterceptorFor = (instance, tracer) => hookName => ({
  300. register: ({ name, type, context, fn }) => {
  301. const newFn = makeNewProfiledTapFn(hookName, tracer, {
  302. name,
  303. type,
  304. fn
  305. });
  306. return {
  307. name,
  308. type,
  309. context,
  310. fn: newFn
  311. };
  312. }
  313. });
  314. // TODO improve typing
  315. /** @typedef {(...args: TODO[]) => void | Promise<TODO>} PluginFunction */
  316. /**
  317. * @param {string} hookName Name of the hook to profile.
  318. * @param {Trace} tracer The trace object.
  319. * @param {object} options Options for the profiled fn.
  320. * @param {string} options.name Plugin name
  321. * @param {string} options.type Plugin type (sync | async | promise)
  322. * @param {PluginFunction} options.fn Plugin function
  323. * @returns {PluginFunction} Chainable hooked function.
  324. */
  325. const makeNewProfiledTapFn = (hookName, tracer, { name, type, fn }) => {
  326. const defaultCategory = ["blink.user_timing"];
  327. switch (type) {
  328. case "promise":
  329. return (...args) => {
  330. const id = ++tracer.counter;
  331. tracer.trace.begin({
  332. name,
  333. id,
  334. cat: defaultCategory
  335. });
  336. const promise = /** @type {Promise<*>} */ (fn(...args));
  337. return promise.then(r => {
  338. tracer.trace.end({
  339. name,
  340. id,
  341. cat: defaultCategory
  342. });
  343. return r;
  344. });
  345. };
  346. case "async":
  347. return (...args) => {
  348. const id = ++tracer.counter;
  349. tracer.trace.begin({
  350. name,
  351. id,
  352. cat: defaultCategory
  353. });
  354. const callback = args.pop();
  355. fn(...args, (...r) => {
  356. tracer.trace.end({
  357. name,
  358. id,
  359. cat: defaultCategory
  360. });
  361. callback(...r);
  362. });
  363. };
  364. case "sync":
  365. return (...args) => {
  366. const id = ++tracer.counter;
  367. // Do not instrument ourself due to the CPU
  368. // profile needing to be the last event in the trace.
  369. if (name === pluginName) {
  370. return fn(...args);
  371. }
  372. tracer.trace.begin({
  373. name,
  374. id,
  375. cat: defaultCategory
  376. });
  377. let r;
  378. try {
  379. r = fn(...args);
  380. } catch (error) {
  381. tracer.trace.end({
  382. name,
  383. id,
  384. cat: defaultCategory
  385. });
  386. throw error;
  387. }
  388. tracer.trace.end({
  389. name,
  390. id,
  391. cat: defaultCategory
  392. });
  393. return r;
  394. };
  395. default:
  396. break;
  397. }
  398. };
  399. module.exports = ProfilingPlugin;
  400. module.exports.Profiler = Profiler;