feat(logging): Allow log to a file (#954)

This feature adds the ability to log to a "stryker.log" file using a separate log level.

You can configure it like this:

```js
// stryker.conf.js
module.exports = function(config) {
  config.set({
    fileLogLevel: 'trace' // defaults to 'off'
  });
}
```

**Note:** The console logger can still be configured as expected using `logLevel: 'info'`.

This also adds logging to the stryker api. Plugin creators can now opt into stryker logging using the new logging api:

```ts
import { getLogger, Logger } from 'stryker-api/logging';
const logger: Logger = getLogger('myLoggerCategory');
```

They no longer have to 'role their own config'. Stryker will take care of the logging appearing in the expected places (console and file).

Fixes #748

.gitignore

@@ -1,6 +1,7 @@
 node_modules
 lerna-debug.log
 npm-debug.log
+stryker.log
 
 coverage
 reports

integrationTest/test/jasmine-jasmine/package.json

@@ -5,7 +5,7 @@
   "description": "A module to perform an integration test",
   "main": "index.js",
   "scripts": {
-    "pretest": "rimraf \"reports\" \"verify/*.map\" && tsc -p .",
+    "pretest": "rimraf \"reports\" \"verify/*.map\" \"stryker.log\"",
     "test": "stryker run",
     "posttest": "mocha --require ts-node/register verify/*.ts"
   },

integrationTest/test/jasmine-jasmine/stryker.conf.js

@@ -1,3 +1,4 @@
+const { LogLevel } = require('stryker-api/core');
 module.exports = function (config) {
   config.set({
     mutate: ['lib/**/*.js'],
@@ -6,7 +7,8 @@ module.exports = function (config) {
     testFramework: 'jasmine',
     testRunner: 'jasmine',
     reporter: ['clear-text', 'event-recorder'],
-    maxConcurrentTestRunners: 2,
-    jasmineConfigFile: 'spec/support/jasmine.json'
+    maxConcurrentTestRunners: 1,
+    jasmineConfigFile: 'spec/support/jasmine.json',
+    fileLogLevel: LogLevel.Debug
   });
 };

integrationTest/test/jasmine-jasmine/verify/verify.ts

@@ -14,4 +14,12 @@ describe('After running stryker with test runner jasmine, test framework jasmine
     expect(scoreResult.noCoverage).eq(1);
     expect(scoreResult.mutationScore).greaterThan(85).and.lessThan(86);
   });
+
+  it('should write to a log file', async () => {
+    const strykerLog = await fs.readFile('./stryker.log', 'utf8');
+    expect(strykerLog).contains('INFO InputFileResolver Found 2 of 10 file(s) to be mutated');
+    expect(strykerLog).matches(/Stryker Done in \d+ seconds/);
+    // TODO, we now have an error because of a memory leak: https://github.com/jasmine/jasmine-npm/issues/134
+    // expect(strykerLog).not.contains('ERROR'); 
+  });
 });

package.json

@@ -12,7 +12,6 @@
     "@types/istanbul": "^0.4.29",
     "@types/karma": "^1.7.4",
     "@types/lodash": "^4.14.110",
-    "@types/log4js": "0.0.32",
     "@types/mkdirp": "^0.5.2",
     "@types/mocha": "^2.2.44",
     "@types/mz": "0.0.32",

packages/stryker-api/core.ts

@@ -5,4 +5,5 @@ export { default as Position } from './src/core/Position';
 export { default as Location } from './src/core/Location';
 export { default as Range } from './src/core/Range';
 export { default as MutatorDescriptor } from './src/core/MutatorDescriptor';
-export { default as MutationScoreThresholds } from './src/core/MutationScoreThresholds';
+export { default as MutationScoreThresholds } from './src/core/MutationScoreThresholds';
+export { default as LogLevel } from './src/core/LogLevel';

packages/stryker-api/logging.ts

@@ -0,0 +1,4 @@
+export { default as LoggerFactory } from './src/logging/LoggerFactory';
+export { default as Logger } from './src/logging/Logger';
+export { default as LoggerFactoryMethod } from './src/logging/LoggerFactoryMethod';
+export { default as getLogger } from './src/logging/getLogger';

packages/stryker-api/src/config/Config.ts

@@ -1,4 +1,4 @@
-import { StrykerOptions, MutatorDescriptor, MutationScoreThresholds } from '../../core';
+import { LogLevel, StrykerOptions, MutatorDescriptor, MutationScoreThresholds } from '../../core';
 
 export default class Config implements StrykerOptions {
 
@@ -7,7 +7,8 @@ export default class Config implements StrykerOptions {
   files: string[];
   mutate: string[];
 
-  logLevel = 'info';
+  logLevel: LogLevel = LogLevel.Information;
+  fileLogLevel: LogLevel = LogLevel.Off;
   timeoutMs = 5000;
   timeoutFactor = 1.5;
   plugins: string[] = ['stryker-*'];

packages/stryker-api/src/core/LogLevel.ts

@@ -0,0 +1,12 @@
+
+enum LogLevel {
+  Off = 'off',
+  Fatal = 'fatal',
+  Error = 'error',
+  Warning = 'warn',
+  Information = 'info',
+  Debug = 'debug',
+  Trace = 'trace'
+}
+
+export default LogLevel;

packages/stryker-api/src/core/StrykerOptions.ts

@@ -1,30 +1,31 @@
 import MutationScoreThresholds from './MutationScoreThresholds';
 import MutatorDescriptor from './MutatorDescriptor';
+import LogLevel from './LogLevel';
 
 interface StrykerOptions {
-  // this ensures that custom config for for example 'karma' can be added under the 'karma' key
+  // this ensures that plugins can load custom config.
   [customConfig: string]: any;
 
   /**
-   * The files array determines which files are in scope for mutation testing.
-   * These include library files, test files and files to mutate, but should NOT include test framework files (for example jasmine).
-   * Each element can be either a string or an object with 2 properties
-   * * `string`: A globbing expression used for selecting the files needed to run the tests.
-   * * { pattern: 'pattern', included: true, mutated: false, transpiled: true }: 
-   *    * The `pattern` property is mandatory and contains the globbing expression used for selecting the files
-   *    * The `included` property is optional and determines whether or not this file should be loaded initially by the test-runner (default: true)
-   *    * The `mutated` property is optional and determines whether or not this file should be targeted for mutations (default: false)
-   *    * The `transpiled` property is optional and determines whether or not this file should be transpiled by a transpiler (see `transpilers` config option) (default: true)
-   * 
-   * @example
-   *     files: ['test/helpers/**\/*.js', 'test/unit/**\/*.js', { pattern: 'src/**\/*.js', included: false }],
+   * A list of globbing expression used for selecting the files that should be mutated.
    */
-  files?: string[];
+  mutate?: string[];
 
   /**
-   * A list of globbing expression used for selecting the files that should be mutated.
+   * With `files` you can choose which files should be included in your test runner sandbox. 
+   * This is normally not needed as it defaults to all files not ignored by git. 
+   * Try it out yourself with this command: `git ls-files --others --exclude-standard --cached --exclude .stryker-tmp`.
+   * 
+   * If you do need to override `files` (for example: when your project does not live in a git repository),
+   * you can override the files here.
+   * 
+   * When using the command line, the list can only contain a comma separated list of globbing expressions.  
+   * When using the config file you can provide an array with `string`s
+   * 
+   * You can *ignore* files by adding an exclamation mark (`!`) at the start of an expression.
+   * 
    */
-  mutate?: string[];
+  files?: string[];
 
   /**
    * Specify the maximum number of concurrent test runners. Useful if you don't want to use
@@ -104,9 +105,15 @@ interface StrykerOptions {
   reporter?: string | string[];
 
   /**
-   * The log4js log level. Possible values: fatal, error, warn, info, debug, trace, all and off. Default is "info"
+   * The log level for logging to a file. If defined, stryker will output a log file called "stryker.log".
+   * Default: "off"
+   */
+  fileLogLevel?: LogLevel;
+
+  /**
+   * The log level for logging to the console. Default: "info".
    */
-  logLevel?: string;
+  logLevel?: LogLevel;
 
   /**
    * Indicates whether or not to symlink the node_modules folder inside the sandbox folder(s).

packages/stryker-api/src/logging/Logger.ts

@@ -0,0 +1,15 @@
+export default interface Logger {
+  isTraceEnabled(): boolean;
+  isDebugEnabled(): boolean;
+  isInfoEnabled(): boolean;
+  isWarnEnabled(): boolean;
+  isErrorEnabled(): boolean;
+  isFatalEnabled(): boolean;
+
+  trace(message: string, ...args: any[]): void;
+  debug(message: string, ...args: any[]): void;
+  info(message: string, ...args: any[]): void;
+  warn(message: string, ...args: any[]): void;
+  error(message: string, ...args: any[]): void;
+  fatal(message: string, ...args: any[]): void;
+}

packages/stryker-api/src/logging/LoggerFactory.ts

@@ -0,0 +1,30 @@
+import LoggerFactoryMethod from './LoggerFactoryMethod';
+import Logger from './Logger';
+
+const noopLogger: Logger = {
+  isTraceEnabled(): boolean { return false; },
+  isDebugEnabled(): boolean { return false; },
+  isInfoEnabled(): boolean { return false; },
+  isWarnEnabled(): boolean { return false; },
+  isErrorEnabled(): boolean { return false; },
+  isFatalEnabled(): boolean { return false; },
+  trace(): void { },
+  debug(): void { },
+  info(): void { },
+  warn(): void { },
+  error(): void { },
+  fatal(): void { }
+};
+
+let logImplementation: LoggerFactoryMethod = () => noopLogger;
+
+export default class LoggerFactory {
+
+  static setLogImplementation(implementation: LoggerFactoryMethod) {
+    logImplementation = implementation;
+  }
+
+  static getLogger: LoggerFactoryMethod = (categoryName?: string) => {
+    return logImplementation(categoryName);
+  }
+}

packages/stryker-api/src/logging/LoggerFactoryMethod.ts

@@ -0,0 +1,12 @@
+import Logger from './Logger';
+
+/**
+ * Represents a factory to get loggers by category name.
+ * This interface is used to describe the shape of a logger factory method.
+ *
+ * @param   {String} [categoryName] name of category to log to.
+ * @returns {Logger} instance of logger for the category
+ */
+export default interface LoggerFactoryMethod {
+    (categoryName?: string): Logger;
+}

packages/stryker-api/src/logging/getLogger.ts

@@ -0,0 +1,6 @@
+import LoggerFactory from './LoggerFactory';
+import LoggerFactoryMethod from './LoggerFactoryMethod';
+
+const getLogger: LoggerFactoryMethod = LoggerFactory.getLogger;
+
+export default getLogger;

packages/stryker-api/test/integration/install-module/install-module.ts

@@ -8,10 +8,20 @@ describe('we have a module using stryker', function () {
 
   const modulePath = path.resolve(__dirname, '../../../testResources/module');
 
-  const execInModule = (command: string) => {
-    console.log(`Exec '${command}' in ${modulePath}`);
-    return exec(command, { cwd: modulePath });
-  };
+  function execInModule (command: string): Promise<[string, string]> {
+    return new Promise((res, rej) => {
+      console.log(`Exec '${command}' in ${modulePath}`);
+      exec(command, { cwd: modulePath }, (error, stdout, stderr) => {
+        if (error) {
+          console.log(stdout);
+          console.error(stderr);
+          rej(error);
+        } else {
+          res([stdout, stderr]);
+        }
+      });
+    });
+  }
 
   describe('after installing Stryker', () => {
 

packages/stryker-api/test/unit/core/LogLevelSpec.ts

@@ -0,0 +1,19 @@
+import { expect } from 'chai';
+import LogLevel from '../../../src/core/LogLevel';
+
+describe('LogLevel', () => {
+
+  function arrangeActAssertLogLevel(actual: LogLevel, expected: string) {
+    it(`should provide "${expected}" for log level "${actual}"`, () => {
+      expect(actual).eq(expected);
+    });
+  }
+
+  arrangeActAssertLogLevel(LogLevel.Off, 'off');
+  arrangeActAssertLogLevel(LogLevel.Fatal, 'fatal');
+  arrangeActAssertLogLevel(LogLevel.Error, 'error');
+  arrangeActAssertLogLevel(LogLevel.Warning, 'warn');
+  arrangeActAssertLogLevel(LogLevel.Information, 'info');
+  arrangeActAssertLogLevel(LogLevel.Debug, 'debug');
+  arrangeActAssertLogLevel(LogLevel.Trace, 'trace');
+});

packages/stryker-api/testResources/module/useCore.ts

@@ -1,4 +1,4 @@
-import { StrykerOptions, Factory, File,  Position, Location, Range } from 'stryker-api/core';
+import { StrykerOptions, Factory, File,  Position, Location, Range, LogLevel } from 'stryker-api/core';
 
 const options: StrykerOptions = {};
 const optionsAllArgs: StrykerOptions = {
@@ -8,7 +8,7 @@ const optionsAllArgs: StrykerOptions = {
   testFramework: 'string',
   testRunner: 'string',
   reporter: 'string',
-  logLevel: 'string',
+  logLevel: LogLevel.Fatal,
   timeoutMs: 1,
   timeoutFactor: 2,
   plugins: ['string'],

packages/stryker-babel-transpiler/package.json

@@ -45,7 +45,6 @@
   "license": "Apache-2.0",
   "dependencies": {
     "babel-core": "6.26.3",
-    "log4js": "~1.1.1",
     "minimatch": "~3.0.4"
   },
   "devDependencies": {
@@ -60,7 +59,7 @@
   },
   "peerDependencies": {
     "babel-core": "^6.26.0",
-    "stryker-api": ">=0.15.0 <0.18.0"
+    "stryker-api": "^0.18.0"
   },
   "initStrykerConfig": {
     "babelrcFile": ".babelrc",

packages/stryker-babel-transpiler/src/BabelConfigReader.ts

@@ -2,13 +2,12 @@ import * as fs from 'fs';
 import * as path from 'path';
 import { Config } from 'stryker-api/config';
 import { CONFIG_KEY_FILE, CONFIG_KEY_OPTIONS } from './helpers/keys';
-import { getLogger, setGlobalLogLevel } from 'log4js';
+import { getLogger } from 'stryker-api/logging';
 
 export default class BabelConfigReader {
   private readonly log = getLogger(BabelConfigReader.name);
 
   public readConfig(config: Config): babel.TransformOptions {
-    setGlobalLogLevel(config.logLevel);
     const babelConfig: babel.TransformOptions = config[CONFIG_KEY_OPTIONS] || this.getConfigFile(config) || {};
     this.log.debug(`babel config is: ${JSON.stringify(babelConfig, null, 2)}`);
     return babelConfig;

packages/stryker-babel-transpiler/src/BabelTranspiler.ts

@@ -5,7 +5,6 @@ import * as path from 'path';
 import BabelConfigReader from './BabelConfigReader';
 import { CONFIG_KEY_FILE } from './helpers/keys';
 import { toJSFileName } from './helpers/helpers';
-import { setGlobalLogLevel } from 'log4js';
 
 const KNOWN_EXTENSIONS = Object.freeze([
   '.es6',
@@ -21,7 +20,6 @@ class BabelTranspiler implements Transpiler {
   private projectRoot: string;
 
   public constructor(options: TranspilerOptions) {
-    setGlobalLogLevel(options.config.logLevel);
     this.babelOptions = new BabelConfigReader().readConfig(options.config);
     this.projectRoot = this.determineProjectRoot(options);
     if (options.produceSourceMaps) {

packages/stryker-babel-transpiler/test/unit/BabelConfigReaderSpec.ts

@@ -2,7 +2,7 @@ import BabelConfigReader from '../../src/BabelConfigReader';
 import { Config } from 'stryker-api/config';
 import { expect } from 'chai';
 import * as fs from 'fs';
-import * as log4js from 'log4js';
+import * as logging from 'stryker-api/logging';
 import * as sinon from 'sinon';
 import * as path from 'path';
 
@@ -24,7 +24,7 @@ describe('BabelConfigReader', () => {
       debug: sandbox.stub()
     };
 
-    sandbox.stub(log4js, 'getLogger').returns(logStub);
+    sandbox.stub(logging, 'getLogger').returns(logStub);
   });
 
   afterEach(() => {

packages/stryker-html-reporter/package.json

@@ -38,14 +38,13 @@
   "dependencies": {
     "file-url": "~2.0.0",
     "lodash": "~4.17.10",
-    "log4js": "~1.1.1",
     "mkdirp": "~0.5.1",
     "mz": "~2.7.0",
     "rimraf": "~2.6.1",
     "typed-html": "~0.6.0"
   },
   "peerDependencies": {
-    "stryker-api": ">=0.15.0 <0.18.0"
+    "stryker-api": "^0.18.0"
   },
   "devDependencies": {
     "@types/file-url": "~2.0.0",