From 4d23c1f4236bc58dcca39ce32dcc3b5374f10a60 Mon Sep 17 00:00:00 2001 From: Ovidiu Viorel Iepure Date: Thu, 3 Nov 2016 07:41:55 -0700 Subject: [PATCH] Instrumentation API Reviewed By: cpojer Differential Revision: D4074413 fbshipit-source-id: fd2dff17168f426680fd9dc8456f8b1ae3f55318 --- react-packager/index.js | 8 +- react-packager/src/Activity/Types.js | 37 ----- .../src/Activity/__tests__/Activity-test.js | 101 ------------ react-packager/src/Activity/formatData.js | 42 ----- react-packager/src/Activity/index.js | 125 --------------- .../src/Activity/normaliseEventData.js | 41 ----- .../src/Bundler/__tests__/Bundler-test.js | 2 +- react-packager/src/Bundler/index.js | 23 +-- react-packager/src/JSTransformer/index.js | 13 +- react-packager/src/Logger/Types.js | 33 ++++ .../{Activity => Logger}/__mocks__/chalk.js | 0 .../src/Logger/__tests__/Logger-test.js | 65 ++++++++ react-packager/src/Logger/index.js | 147 ++++++++++++++++++ react-packager/src/Resolver/index.js | 2 - .../src/Server/__tests__/Server-test.js | 2 +- react-packager/src/Server/index.js | 85 +++++----- .../__tests__/DependencyGraph-test.js | 4 +- react-packager/src/node-haste/fastfs.js | 26 ++-- react-packager/src/node-haste/index.js | 37 ++--- 19 files changed, 335 insertions(+), 458 deletions(-) delete mode 100644 react-packager/src/Activity/Types.js delete mode 100644 react-packager/src/Activity/__tests__/Activity-test.js delete mode 100644 react-packager/src/Activity/formatData.js delete mode 100644 react-packager/src/Activity/index.js delete mode 100644 react-packager/src/Activity/normaliseEventData.js create mode 100644 react-packager/src/Logger/Types.js rename react-packager/src/{Activity => Logger}/__mocks__/chalk.js (100%) create mode 100644 react-packager/src/Logger/__tests__/Logger-test.js create mode 100644 react-packager/src/Logger/index.js diff --git a/react-packager/index.js b/react-packager/index.js index 162ee703..e8f31d07 100644 --- a/react-packager/index.js +++ b/react-packager/index.js @@ -10,11 +10,11 @@ require('../babelRegisterOnly')([/react-packager\/src/]); -var debug = require('debug'); -var Activity = require('./src/Activity'); +const debug = require('debug'); +const Logger = require('./src/Logger'); exports.createServer = createServer; -exports.Activity = Activity; +exports.Logger = Logger; exports.getOrderedDependencyPaths = function(options, bundleOptions) { var server = createNonPersistentServer(options); return server.getOrderedDependencyPaths(bundleOptions) @@ -50,7 +50,7 @@ function createServer(options) { } function createNonPersistentServer(options) { - Activity.disable(); + Logger.disablePrinting(); // Don't start the filewatcher or the cache. if (options.nonPersistent == null) { options.nonPersistent = true; diff --git a/react-packager/src/Activity/Types.js b/react-packager/src/Activity/Types.js deleted file mode 100644 index 80aea02b..00000000 --- a/react-packager/src/Activity/Types.js +++ /dev/null @@ -1,37 +0,0 @@ -/** - * Copyright (c) 2015-present, Facebook, Inc. - * All rights reserved. - * - * This source code is licensed under the BSD-style license found in the - * LICENSE file in the root directory of this source tree. An additional grant - * of patent rights can be found in the PATENTS file in the same directory. - * - * @flow - * - */ -'use strict'; - -export type Options = { - telemetric?: boolean, - silent?: boolean, - displayFields?: Array | true, -}; - -type EventFieldDescriptor = { - type: 'int' | 'normal', - value: number | string | boolean, -}; - -export type NormalisedEventData = {[key: string]: EventFieldDescriptor}; - -export type EventData = {[key: string]: number | string | boolean}; - -export type Event = { - data: NormalisedEventData, - durationMs?: number, - id: number, - name: string, - options: Options, - session: string, - startTimeStamp: [number, number], -}; diff --git a/react-packager/src/Activity/__tests__/Activity-test.js b/react-packager/src/Activity/__tests__/Activity-test.js deleted file mode 100644 index a8153426..00000000 --- a/react-packager/src/Activity/__tests__/Activity-test.js +++ /dev/null @@ -1,101 +0,0 @@ -/** - * Copyright (c) 2015-present, Facebook, Inc. - * All rights reserved. - * - * This source code is licensed under the BSD-style license found in the - * LICENSE file in the root directory of this source tree. An additional grant - * of patent rights can be found in the PATENTS file in the same directory. - */ -'use strict'; - -jest.disableAutomock(); - -var Activity = require('../'); - -describe('Activity', () => { - // eslint-disable-next-line no-console-disallow - const origConsoleLog = console.log; - - beforeEach(() => { - // eslint-disable-next-line no-console-disallow - console.log = jest.fn(); - jest.runOnlyPendingTimers(); - }); - - afterEach(() => { - // eslint-disable-next-line no-console-disallow - console.log = origConsoleLog; - }); - - describe('startEvent', () => { - it('writes the "START" phase of non-silent events to the console', () => { - const EVENT_NAME = 'EVENT_NAME'; - const DATA = {someData: 42}; - - Activity.startEvent(EVENT_NAME, DATA, {displayFields: ['someData']}); - jest.runOnlyPendingTimers(); - - // eslint-disable-next-line no-console-disallow - expect(console.log.mock.calls.length).toBe(1); - // eslint-disable-next-line no-console-disallow - const consoleMsg = console.log.mock.calls[0][0]; - expect(consoleMsg).toContain('START'); - expect(consoleMsg).toContain(EVENT_NAME); - expect(consoleMsg).toContain('someData: 42'); - }); - - it('does not write the "START" phase of silent events to the console', () => { - const EVENT_NAME = 'EVENT_NAME'; - const DATA = {someData: 42}; - - Activity.startEvent(EVENT_NAME, DATA, {silent: true}); - jest.runOnlyPendingTimers(); - - // eslint-disable-next-line no-console-disallow - expect(console.log.mock.calls.length).toBe(0); - }); - }); - - describe('endEvent', () => { - it('writes the "END" phase of non-silent events to the console', () => { - const EVENT_NAME = 'EVENT_NAME'; - const DATA = {someData: 42}; - - const eventID = Activity.startEvent(EVENT_NAME, DATA, {displayFields: ['someData']}); - Activity.endEvent(eventID); - jest.runOnlyPendingTimers(); - - // eslint-disable-next-line no-console-disallow - expect(console.log.mock.calls.length).toBe(2); - // eslint-disable-next-line no-console-disallow - const consoleMsg = console.log.mock.calls[1][0]; - expect(consoleMsg).toContain('END'); - expect(consoleMsg).toContain(EVENT_NAME); - expect(consoleMsg).toContain('someData: 42'); - }); - - it('does not write the "END" phase of silent events to the console', () => { - const EVENT_NAME = 'EVENT_NAME'; - const DATA = {someData: 42}; - - const eventID = Activity.startEvent(EVENT_NAME, DATA, {silent: true}); - Activity.endEvent(eventID); - jest.runOnlyPendingTimers(); - - // eslint-disable-next-line no-console-disallow - expect(console.log.mock.calls.length).toBe(0); - }); - - it('throws when called with an invalid eventId', () => { - expect(() => Activity.endEvent(42)).toThrow(); - }); - - it('throws when called with an expired eventId', () => { - const eid = Activity.startEvent('', ''); - Activity.endEvent(eid); - expect(() => { - Activity.endEvent(eid); - }).toThrow(); - }); - }); -}); diff --git a/react-packager/src/Activity/formatData.js b/react-packager/src/Activity/formatData.js deleted file mode 100644 index a4c0f586..00000000 --- a/react-packager/src/Activity/formatData.js +++ /dev/null @@ -1,42 +0,0 @@ -/** - * Copyright (c) 2015-present, Facebook, Inc. - * All rights reserved. - * - * This source code is licensed under the BSD-style license found in the - * LICENSE file in the root directory of this source tree. An additional grant - * of patent rights can be found in the PATENTS file in the same directory. - * - * @flow - * - */ -'use strict'; - -import type {Event} from './Types'; - -function getDataString(event: Event): string { - const {options, data} = event; - const {displayFields} = options; - - if (!Object.keys(data).length || - !(Array.isArray(displayFields) || displayFields === true)) { - return ''; - } - - const fields = Array.isArray(displayFields) ? displayFields : Object.keys(data); - const dataList = fields.map(field => { - if (data[field] === undefined) { - throw new Error(`"${field}" is not defined for event ""${event.name}"!`); - } - return `${field}: ${data[field].value.toString()}`; - }); - - let dataString = dataList.join(' | '); - - if (dataString) { - dataString = ` ${dataString} `; - } - - return dataString; -} - -module.exports = getDataString; diff --git a/react-packager/src/Activity/index.js b/react-packager/src/Activity/index.js deleted file mode 100644 index 7eac9f84..00000000 --- a/react-packager/src/Activity/index.js +++ /dev/null @@ -1,125 +0,0 @@ -/** - * Copyright (c) 2015-present, Facebook, Inc. - * All rights reserved. - * - * This source code is licensed under the BSD-style license found in the - * LICENSE file in the root directory of this source tree. An additional grant - * of patent rights can be found in the PATENTS file in the same directory. - * - * @flow - * - */ -'use strict'; - -import type {Event, EventData, Options} from './Types'; - -const chalk = require('chalk'); -const events = require('events'); -const formatData = require('./formatData'); -const normaliseEventData = require('./normaliseEventData'); -const os = require('os'); - -let ENABLED = true; -let UUID = 1; - -const session = `${os.hostname()}-${Date.now()}`; -const EVENT_INDEX: {[key: number]: Event} = Object.create(null); -const EVENT_EMITTER = new events.EventEmitter(); - -function startEvent(name: string, data: EventData = {}, options: Options = {}): number { - if (name == null) { - throw new Error('No event name specified!'); - } - - const id = UUID++; - EVENT_INDEX[id] = { - data: normaliseEventData(data), - id, - options, - name, - session, - startTimeStamp: process.hrtime(), - }; - logEvent(id, 'startEvent'); - - return id; -} - -function endEvent(id: number): void { - const event = getEvent(id); - const delta = process.hrtime(event.startTimeStamp); - event.durationMs = Math.round((delta[0] * 1e9 + delta[1]) / 1e6); - logEvent(id, 'endEvent'); -} - -function getEvent(id: number): Event { - if (!EVENT_INDEX[id]) { - throw new Error(`Event(${id}) either ended or never started`); - } - - return EVENT_INDEX[id]; -} - -function forgetEvent(id: number): void { - delete EVENT_INDEX[id]; -} - -function logEvent(id: number, phase: 'startEvent' | 'endEvent'): void { - const event = getEvent(id); - EVENT_EMITTER.emit(phase, id); - - if (!ENABLED) { - return; - } - - const { - name, - durationMs, - options, - } = event; - - const logTimeStamp = new Date().toLocaleString(); - const dataString = formatData(event); - const {telemetric, silent} = options; - - switch (phase) { - case 'startEvent': - if (!silent) { - // eslint-disable-next-line no-console-disallow - console.log(chalk.dim(`[${logTimeStamp}] ${name}${dataString}`)); - } - break; - - case 'endEvent': - if (!silent) { - // eslint-disable-next-line no-console-disallow - console.log( - chalk.dim(`[${logTimeStamp}] ${name}${dataString}`) + - (telemetric ? chalk.reset.cyan(` (${+durationMs}ms)`) : chalk.dim(` (${+durationMs}ms)`)) - ); - } - forgetEvent(id); - break; - - default: - throw new Error(`Unexpected event phase "${phase}"!`); - } -} - -function enable(): void { - ENABLED = true; -} - -function disable(): void { - ENABLED = false; -} - -module.exports = { - startEvent, - endEvent, - getEvent, - forgetEvent, - enable, - disable, - eventEmitter: EVENT_EMITTER, -}; diff --git a/react-packager/src/Activity/normaliseEventData.js b/react-packager/src/Activity/normaliseEventData.js deleted file mode 100644 index df0da238..00000000 --- a/react-packager/src/Activity/normaliseEventData.js +++ /dev/null @@ -1,41 +0,0 @@ -/** - * Copyright (c) 2015-present, Facebook, Inc. - * All rights reserved. - * - * This source code is licensed under the BSD-style license found in the - * LICENSE file in the root directory of this source tree. An additional grant - * of patent rights can be found in the PATENTS file in the same directory. - * - * @flow - * - */ -'use strict'; - -import type {EventData, NormalisedEventData} from './Types'; - -function normaliseEventData(eventData: EventData): NormalisedEventData { - if (!eventData) { - return {}; - } - - const normalisedEventData = {}; - - Object.keys(eventData).forEach(field => { - const value = eventData[field]; - let type; - - if (typeof value === 'string' || typeof value === 'boolean') { - type = 'normal'; - } else if (typeof value === 'number') { - type = 'int'; - } else { - throw new Error(`Disallowed value for event field "${field}""!`); - } - - normalisedEventData[field] = {type, value}; - }); - - return normalisedEventData; -} - -module.exports = normaliseEventData; diff --git a/react-packager/src/Bundler/__tests__/Bundler-test.js b/react-packager/src/Bundler/__tests__/Bundler-test.js index a74d9e5d..6faf646b 100644 --- a/react-packager/src/Bundler/__tests__/Bundler-test.js +++ b/react-packager/src/Bundler/__tests__/Bundler-test.js @@ -24,7 +24,7 @@ jest .mock('../Bundle') .mock('../PrepackBundle') .mock('../HMRBundle') - .mock('../../Activity') + .mock('../../Logger') .mock('../../lib/declareOpts'); var Bundler = require('../'); diff --git a/react-packager/src/Bundler/index.js b/react-packager/src/Bundler/index.js index d1c2dbc6..d8544a8e 100644 --- a/react-packager/src/Bundler/index.js +++ b/react-packager/src/Bundler/index.js @@ -19,7 +19,6 @@ const Resolver = require('../Resolver'); const Bundle = require('./Bundle'); const HMRBundle = require('./HMRBundle'); const PrepackBundle = require('./PrepackBundle'); -const Activity = require('../Activity'); const ModuleTransport = require('../lib/ModuleTransport'); const declareOpts = require('../lib/declareOpts'); const imageSize = require('image-size'); @@ -29,6 +28,13 @@ const sizeOf = Promise.denodeify(imageSize); const noop = () => {}; +const { + createActionStartEntry, + createActionEndEntry, + log, + print, +} = require('../Logger'); + const validateOpts = declareOpts({ projectRoots: { type: 'array', @@ -364,16 +370,13 @@ class Bundler { finalizeBundle = noop, onProgress = noop, }) { - const findEventId = Activity.startEvent( - 'Transforming modules', - { + const transformingFilesLogEntry = + print(log(createActionStartEntry({ + action_name: 'Transforming files', entry_point: entryFile, environment: dev ? 'dev' : 'prod', - }, - { - telemetric: true, - }, - ); + }))); + const modulesByName = Object.create(null); if (!resolutionResponse) { @@ -392,7 +395,7 @@ class Bundler { return Promise.resolve(resolutionResponse).then(response => { bundle.setRamGroups(response.transformOptions.transform.ramGroups); - Activity.endEvent(findEventId); + print(log(createActionEndEntry(transformingFilesLogEntry))); onResolutionResponse(response); // get entry file complete path (`entryFile` is relative to roots) diff --git a/react-packager/src/JSTransformer/index.js b/react-packager/src/JSTransformer/index.js index e3f64e5a..30dc4d7b 100644 --- a/react-packager/src/JSTransformer/index.js +++ b/react-packager/src/JSTransformer/index.js @@ -8,8 +8,8 @@ */ 'use strict'; -const Activity = require('../Activity'); const Promise = require('promise'); + const declareOpts = require('../lib/declareOpts'); const os = require('os'); const util = require('util'); @@ -112,21 +112,10 @@ class Transformer { return Promise.reject(new Error('No transform module')); } debug('transforming file', fileName); - const transformEventId = Activity.startEvent( - 'Transforming file', - { - file_name: fileName, - }, - { - telemetric: true, - silent: true, - }, - ); return this ._transform(this._transformModulePath, fileName, code, options) .then(result => { debug('done transforming file', fileName); - Activity.endEvent(transformEventId); return result; }) .catch(error => { diff --git a/react-packager/src/Logger/Types.js b/react-packager/src/Logger/Types.js new file mode 100644 index 00000000..b2dfab4b --- /dev/null +++ b/react-packager/src/Logger/Types.js @@ -0,0 +1,33 @@ +/** + * Copyright (c) 2015-present, Facebook, Inc. + * All rights reserved. + * + * This source code is licensed under the BSD-style license found in the + * LICENSE file in the root directory of this source tree. An additional grant + * of patent rights can be found in the PATENTS file in the same directory. + * + * @flow + * + */ +'use strict'; + +export type ActionLogEntryData = { + action_name: string, +}; + +export type ActionStartLogEntry = { + action_name?: string, + action_phase?: string, + log_entry_label: string, + log_session?: string, + start_timestamp?: [number, number], +}; + +export type LogEntry = { + action_name?: string, + action_phase?: string, + duration_ms?: number, + log_entry_label: string, + log_session?: string, + start_timestamp?: [number, number], +}; diff --git a/react-packager/src/Activity/__mocks__/chalk.js b/react-packager/src/Logger/__mocks__/chalk.js similarity index 100% rename from react-packager/src/Activity/__mocks__/chalk.js rename to react-packager/src/Logger/__mocks__/chalk.js diff --git a/react-packager/src/Logger/__tests__/Logger-test.js b/react-packager/src/Logger/__tests__/Logger-test.js new file mode 100644 index 00000000..d99f541d --- /dev/null +++ b/react-packager/src/Logger/__tests__/Logger-test.js @@ -0,0 +1,65 @@ +/** + * Copyright (c) 2015-present, Facebook, Inc. + * All rights reserved. + * + * This source code is licensed under the BSD-style license found in the + * LICENSE file in the root directory of this source tree. An additional grant + * of patent rights can be found in the PATENTS file in the same directory. + * + * eslint-disable no-console-disallow + * + */ +'use strict'; + +jest.disableAutomock(); + +const { + createEntry, + createActionStartEntry, + createActionEndEntry, + enablePrinting, +} = require('../'); + +describe('Logger', () => { + const originalConsoleLog = console.log; + + beforeEach(() => { + console.log = jest.fn(); + }); + + afterEach(() => { + console.log = originalConsoleLog; + enablePrinting(); + }); + + it('creates simple log entries', () => { + const logEntry = createEntry('Test'); + expect(logEntry).toEqual({ + log_entry_label: 'Test', + log_session: jasmine.any(String), + }); + }); + + it('creates action start log entries', () => { + const actionStartLogEntry = createActionStartEntry('Test'); + expect(actionStartLogEntry).toEqual({ + action_name: 'Test', + action_phase: 'start', + log_entry_label: 'Test', + log_session: jasmine.any(String), + start_timestamp: jasmine.any(Object), + }); + }); + + it('creates action end log entries', () => { + const actionEndLogEntry = createActionEndEntry(createActionStartEntry('Test')); + expect(actionEndLogEntry).toEqual({ + action_name: 'Test', + action_phase: 'end', + duration_ms: jasmine.any(Number), + log_entry_label: 'Test', + log_session: jasmine.any(String), + start_timestamp: jasmine.any(Object), + }); + }); +}); diff --git a/react-packager/src/Logger/index.js b/react-packager/src/Logger/index.js new file mode 100644 index 00000000..4de1f54d --- /dev/null +++ b/react-packager/src/Logger/index.js @@ -0,0 +1,147 @@ +/** + * Copyright (c) 2015-present, Facebook, Inc. + * All rights reserved. + * + * This source code is licensed under the BSD-style license found in the + * LICENSE file in the root directory of this source tree. An additional grant + * of patent rights can be found in the PATENTS file in the same directory. + * + * @flow + * + */ +'use strict'; + +import type { + ActionLogEntryData, + ActionStartLogEntry, + LogEntry, +} from './Types'; + +const {EventEmitter} = require('events'); + +const chalk = require('chalk'); +const os = require('os'); + +let PRINT_LOG_ENTRIES = true; +const log_session = `${os.hostname()}-${Date.now()}`; +const eventEmitter = new EventEmitter(); + +function on(event: string, handler: (logEntry: LogEntry) => void): void { + eventEmitter.on(event, handler); +} + +function createEntry(data: LogEntry | string): LogEntry { + const logEntry = typeof data === 'string' ? {log_entry_label: data} : data; + + return { + ...logEntry, + log_session, + }; +} + +function createActionStartEntry(data: ActionLogEntryData | string): LogEntry { + const logEntry = typeof data === 'string' ? {action_name: data} : data; + const {action_name} = logEntry; + + return createEntry({ + ...logEntry, + action_name, + action_phase: 'start', + log_entry_label: action_name, + start_timestamp: process.hrtime(), + }); +} + +function createActionEndEntry(logEntry: ActionStartLogEntry): LogEntry { + const { + action_name, + action_phase, + start_timestamp, + } = logEntry; + + if (action_phase !== 'start' || !Array.isArray(start_timestamp)) { + throw new Error('Action has not started or has already ended'); + } + + const timeDelta = process.hrtime(start_timestamp); + const duration_ms = Math.round((timeDelta[0] * 1e9 + timeDelta[1]) / 1e6); + + return createEntry({ + ...logEntry, + action_name, + action_phase: 'end', + duration_ms, + log_entry_label: action_name, + }); +} + +function log(logEntry: LogEntry): LogEntry { + eventEmitter.emit('log', logEntry); + return logEntry; +} + +function print( + logEntry: LogEntry, + printFields?: Array = [], +): LogEntry { + if (!PRINT_LOG_ENTRIES) { + return logEntry; + } + + const {log_entry_label, action_phase, duration_ms} = logEntry; + const timeStamp = new Date().toLocaleString(); + const logEntryDataList = []; + let logEntryString, logEntryDataString; + + for (let i = 0, len = printFields.length; i < len; i++) { + const field = printFields[i]; + const value = logEntry[field]; + if (value === undefined) { + continue; + } + logEntryDataList.push(`${field}: ${value.toString()}`); + } + + logEntryDataString = logEntryDataList.join(' | '); + + if (logEntryDataString) { + logEntryDataString = ` ${logEntryDataString}`; + } + + switch (action_phase) { + case 'start': + logEntryString = chalk.dim(`[${timeStamp}] ${log_entry_label}${logEntryDataString}`); + break; + case 'end': + logEntryString = chalk.dim(`[${timeStamp}] ${log_entry_label}${logEntryDataString}`) + + chalk.cyan(` (${+duration_ms}ms)`); + break; + default: + logEntryString = chalk.dim(`[${timeStamp}] ${log_entry_label}${logEntryDataString}`); + break; + } + + // eslint-disable-next-line no-console-disallow + console.log(logEntryString); + + return logEntry; +} + +function enablePrinting(): void { + PRINT_LOG_ENTRIES = true; +} + +function disablePrinting(): void { + PRINT_LOG_ENTRIES = false; +} + +module.exports = { + on, + createEntry, + createActionStartEntry, + createActionEndEntry, + log, + print, + enablePrinting, + disablePrinting, +}; diff --git a/react-packager/src/Resolver/index.js b/react-packager/src/Resolver/index.js index 2cef5e12..03795552 100644 --- a/react-packager/src/Resolver/index.js +++ b/react-packager/src/Resolver/index.js @@ -9,7 +9,6 @@ 'use strict'; -const Activity = require('../Activity'); const DependencyGraph = require('../node-haste'); const declareOpts = require('../lib/declareOpts'); @@ -89,7 +88,6 @@ class Resolver { const opts = validateOpts(options); this._depGraph = new DependencyGraph({ - activity: Activity, roots: opts.projectRoots, assetRoots_DEPRECATED: opts.assetRoots, assetExts: opts.assetExts, diff --git a/react-packager/src/Server/__tests__/Server-test.js b/react-packager/src/Server/__tests__/Server-test.js index 2a404116..d7dfc2aa 100644 --- a/react-packager/src/Server/__tests__/Server-test.js +++ b/react-packager/src/Server/__tests__/Server-test.js @@ -19,7 +19,7 @@ jest.setMock('worker-farm', function() { return () => {}; }) .mock('../../AssetServer') .mock('../../lib/declareOpts') .mock('../../node-haste') - .mock('../../Activity'); + .mock('../../Logger'); let FileWatcher; diff --git a/react-packager/src/Server/index.js b/react-packager/src/Server/index.js index d5da01dd..5c1eb615 100644 --- a/react-packager/src/Server/index.js +++ b/react-packager/src/Server/index.js @@ -8,7 +8,6 @@ */ 'use strict'; -const Activity = require('../Activity'); const AssetServer = require('../AssetServer'); const FileWatcher = require('../node-haste').FileWatcher; const getPlatformExtension = require('../node-haste').getPlatformExtension; @@ -26,6 +25,13 @@ const url = require('url'); const debug = require('debug')('ReactNativePackager:Server'); +const { + createActionStartEntry, + createActionEndEntry, + log, + print, +} = require('../Logger'); + function debounceAndBatch(fn, delay) { let timeout, args = []; return (value) => { @@ -496,15 +502,13 @@ class Server { _processAssetsRequest(req, res) { const urlObj = url.parse(decodeURI(req.url), true); const assetPath = urlObj.pathname.match(/^\/assets\/(.+)$/); - const assetEvent = Activity.startEvent( - 'Processing asset request', - { + + const processingAssetRequestLogEntry = + print(log(createActionStartEntry({ + action_name: 'Processing asset request', asset: assetPath[1], - }, - { - displayFields: true, - }, - ); + })), ['asset']); + this._assetServer.get(assetPath[1], urlObj.query.platform) .then( data => { @@ -518,7 +522,9 @@ class Server { res.writeHead('404'); res.end('Asset not found'); } - ).done(() => Activity.endEvent(assetEvent)); + ).done(() => { + print(log(createActionEndEntry(processingAssetRequestLogEntry)), ['asset']); + }); } optionsHash(options) { @@ -539,18 +545,15 @@ class Server { const deps = bundleDeps.get(bundle); const {dependencyPairs, files, idToIndex, outdated} = deps; if (outdated.size) { - const updateExistingBundleEventId = - Activity.startEvent( - 'Updating existing bundle', - { - outdated_modules: outdated.size, - }, - { - telemetric: true, - displayFields: true, - }, - ); + + const updatingExistingBundleLogEntry = + print(log(createActionStartEntry({ + action_name: 'Updating existing bundle', + outdated_modules: outdated.size, + })), ['outdated_modules']); + debug('Attempt to update existing bundle'); + const changedModules = Array.from(outdated, this.getModuleForPath, this); deps.outdated = new Set(); @@ -604,8 +607,13 @@ class Server { } bundle.invalidateSource(); + + print( + log(createActionEndEntry(updatingExistingBundleLogEntry)), + ['outdated_modules'], + ); + debug('Successfully updated existing bundle'); - Activity.endEvent(updateExistingBundleEventId); return bundle; }); }).catch(e => { @@ -652,17 +660,12 @@ class Server { } const options = this._getOptionsFromUrl(req.url); - const startReqEventId = Activity.startEvent( - 'Requesting bundle', - { - url: req.url, + const requestingBundleLogEntry = + print(log(createActionStartEntry({ + action_name: 'Requesting bundle', + bundle_url: req.url, entry_point: options.entryFile, - }, - { - telemetric: true, - displayFields: ['url'], - }, - ); + })), ['bundle_url']); let consoleProgress = () => {}; if (process.stdout.isTTY && !this._opts.silent) { @@ -705,7 +708,7 @@ class Server { mres.end(bundleSource); } debug('Finished response'); - Activity.endEvent(startReqEventId); + print(log(createActionEndEntry(requestingBundleLogEntry)), ['bundle_url']); } else if (requestType === 'map') { let sourceMap = p.getSourceMap({ minify: options.minify, @@ -718,12 +721,12 @@ class Server { mres.setHeader('Content-Type', 'application/json'); mres.end(sourceMap); - Activity.endEvent(startReqEventId); + print(log(createActionEndEntry(requestingBundleLogEntry)), ['bundle_url']); } else if (requestType === 'assets') { const assetsList = JSON.stringify(p.getAssets()); mres.setHeader('Content-Type', 'application/json'); mres.end(assetsList); - Activity.endEvent(startReqEventId); + print(log(createActionEndEntry(requestingBundleLogEntry)), ['bundle_url']); } }, error => this._handleError(mres, this.optionsHash(options), error) @@ -735,13 +738,9 @@ class Server { } _symbolicate(req, res) { - const startReqEventId = Activity.startEvent( - 'Symbolicating', - null, - { - telemetric: true, - }, - ); + const symbolicatingLogEntry = + print(log(createActionStartEntry('Symbolicating'))); + new Promise.resolve(req.rawBody).then(body => { const stack = JSON.parse(body).stack; @@ -795,7 +794,7 @@ class Server { res.end(JSON.stringify({error: error.message})); } ).done(() => { - Activity.endEvent(startReqEventId); + print(log(createActionEndEntry(symbolicatingLogEntry))); }); } diff --git a/react-packager/src/node-haste/__tests__/DependencyGraph-test.js b/react-packager/src/node-haste/__tests__/DependencyGraph-test.js index 739404d9..90dbf965 100644 --- a/react-packager/src/node-haste/__tests__/DependencyGraph-test.js +++ b/react-packager/src/node-haste/__tests__/DependencyGraph-test.js @@ -10,7 +10,9 @@ jest.autoMockOff(); jest.useRealTimers(); -jest.mock('fs'); +jest + .mock('fs') + .mock('../../Logger'); // This is an ugly hack: // * jest-haste-map uses `find` for fast file system crawling which won't work diff --git a/react-packager/src/node-haste/fastfs.js b/react-packager/src/node-haste/fastfs.js index 679b14f3..47ac3322 100644 --- a/react-packager/src/node-haste/fastfs.js +++ b/react-packager/src/node-haste/fastfs.js @@ -27,6 +27,13 @@ interface FileWatcher { on(event: 'all', handler: (type: string, filePath: string, rootPath: string, fstat: fs.Stats) => void): void, } +const { + createActionStartEntry, + createActionEndEntry, + log, + print, +} = require('../Logger'); + class Fastfs extends EventEmitter { _name: string; @@ -62,18 +69,10 @@ class Fastfs extends EventEmitter { return new File(root, true); }); this._fastPaths = Object.create(null); - this._activity = activity; - let fastfsActivity; - if (activity) { - fastfsActivity = activity.startEvent( - 'Building in-memory fs for ' + this._name, - null, - { - telemetric: true, - }, - ); - } + const buildingInMemoryFSLogEntry = + print(log(createActionStartEntry('Building in-memory fs for ' + this._name))); + files.forEach(filePath => { const root = this._getRoot(filePath); if (root) { @@ -88,9 +87,8 @@ class Fastfs extends EventEmitter { } } }); - if (activity) { - activity.endEvent(fastfsActivity); - } + + print(log(createActionEndEntry(buildingInMemoryFSLogEntry))); if (this._fileWatcher) { this._fileWatcher.on('all', this._processFileChange.bind(this)); diff --git a/react-packager/src/node-haste/index.js b/react-packager/src/node-haste/index.js index 5358511c..68b95274 100644 --- a/react-packager/src/node-haste/index.js +++ b/react-packager/src/node-haste/index.js @@ -33,14 +33,15 @@ const util = require('util'); const ERROR_BUILDING_DEP_GRAPH = 'DependencyGraphError'; -const defaultActivity = { - startEvent: () => {}, - endEvent: () => {}, -}; +const { + createActionStartEntry, + createActionEndEntry, + log, + print, +} = require('../Logger'); class DependencyGraph { constructor({ - activity, roots, ignoreFilePath, fileWatcher, @@ -65,7 +66,6 @@ class DependencyGraph { resetCache, }) { this._opts = { - activity: activity || defaultActivity, roots, ignoreFilePath: ignoreFilePath || (() => {}), fileWatcher, @@ -116,14 +116,8 @@ class DependencyGraph { }); this._loading = haste.build().then(hasteMap => { - const {activity} = this._opts; - const depGraphActivity = activity.startEvent( - 'Initializing Packager', - null, - { - telemetric: true, - }, - ); + const initializingPackagerLogEntry = + print(log(createActionStartEntry('Initializing Packager'))); const hasteFSFiles = hasteMap.hasteFS.getAllFiles(); @@ -134,7 +128,6 @@ class DependencyGraph { hasteFSFiles, { ignore: this._opts.ignoreFilePath, - activity: activity, } ); @@ -181,17 +174,13 @@ class DependencyGraph { } }); - const hasteActivity = activity.startEvent( - 'Building Haste Map', - null, - { - telemetric: true, - }, - ); + const buildingHasteMapLogEntry = + print(log(createActionStartEntry('Building Haste Map'))); + return this._hasteMap.build().then( map => { - activity.endEvent(hasteActivity); - activity.endEvent(depGraphActivity); + print(log(createActionEndEntry(buildingHasteMapLogEntry))); + print(log(createActionEndEntry(initializingPackagerLogEntry))); return map; }, err => {