ProfilingPlugin.js 9.2 KB

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