Changes to logging

* Remove file logger * Always log to stderr, not stdout * Add loglevel flags to set logging level
wtsi-npg · Dec 21, 2016 · 4b89da4 · 4b89da4
1 parent c036066
commit 4b89da4
Show file tree

Hide file tree

Showing 9 changed files with 60 additions and 55 deletions.
diff --git a/CHANGES b/CHANGES
@@ -12,6 +12,9 @@ LIST OF CHANGES for npg_ranger project
   - do not allow query strings containing multiple attribute-value pairs
     for the same attribute
   - upgrade Freebayes to 1.1.0 from 1.0.2-npg-Aug2016 in TravisCI and docs
+  - remove directly logging to file due to winston bug
+  - add flags to change logging level
+  - all logging output is now sent to stderr
 
 release 1.0.0
   - show error in log when controller tests fail to cleanup

diff --git a/bin/client.js b/bin/client.js
@@ -65,7 +65,7 @@ cline
   .version(require('../package.json').version)
   .description('Command line client for GA4GH data streaming')
   .arguments('<url> [output]')
-  .option('--debug', 'Show debug output')
+  .option('--loglevel <level>', 'level of logging output', /^(error|warn|info|debug)$/i, 'error')
   .option('--accept-trailers', 'Request trailers from server')
   .parse(process.argv);
 
@@ -91,11 +91,7 @@ cline.on('--help', () => {
 if ( !cline.args.length ||
      ( cline.args.length != 1 && cline.args.length != 2 ) ) { cline.help(); }
 
-if ( !cline.debug ) {
-  LOGGER.level = 'warn';
-} else {
-  LOGGER.level = 'debug';
-}
+LOGGER.level = cline.loglevel;
 
 var url    = cline.args[0];
 var output = cline.args.length == 2 ? cline.args[1] : undefined;

diff --git a/bin/server.js b/bin/server.js
@@ -256,9 +256,22 @@ if ( require.main === module ) {
   if ( options.get('version') ) {
     console.log(require('../package.json').version);
     process.exit(0);
-  } else if ( options.get('debug') ) {
-    LOGGER.level = 'debug';
   }
+
+  let loglevel = options.get('loglevel');
+  let knownLevels = ['error', 'warn', 'info', 'debug', 'silly'];
+  if (loglevel) {
+    if (knownLevels.indexOf(loglevel) !== -1) {
+      LOGGER.level = loglevel;
+    } else {
+      // --loglevel was given an invalid parameter - log error and quit
+      LOGGER.error('configuration error: loglevel flag expects one of ' +
+                   knownLevels.join(', ') + ', but actually received ' +
+                   loglevel);
+      process.exit(1);
+    }
+  }
+
   let numWorkers    = options.get('numworkers');
   let waitingConsec = options.get('clustertimeout');
   let maxConsec     = options.get('clustermaxdeaths');

diff --git a/lib/config.js b/lib/config.js
@@ -13,11 +13,11 @@
  *   // The values from this object will override any
  *   // found elsewhere, in config files or similar.
  *   function func() {
- *     return { debug: true };
+ *     return { loglevel: 'debug' };
  *   }
  *   config.provide(func);
- *   // Retrieve the 'debug' setting
- *   options.get('debug'); // true
+ *   // Retrieve the 'loglevel' setting
+ *   options.get('loglevel'); // true
  *
  * @author Andrew Nowak
  * @copyright Genome Research Limited 2016
@@ -56,12 +56,13 @@ const optionsList = [
   ['s','skipauth'             ,'skip authorisation steps'],
   ['' ,'anyorigin'            ,'accept CORS requests from any origin'],
   ['e','emaildomain=DOMAIN'   ,'email domain to validate the remote user value against'],
-  ['d','debug'                ,'debugging mode for this server'],
+  ['' ,'loglevel=[error|warn|info|debug]','set logging level [default: error]'],
   ['V','version'              ,'print version and exit'],
   ['h','help'                 ,'display this help']
 ];
 
 const defaultOptions = {
+  loglevel:         'error',
   [RO_OPTION_KEY]:  false,
   /* cluster */
   numworkers:       1,

diff --git a/lib/logsetup.js b/lib/logsetup.js
@@ -30,19 +30,11 @@ var getTimeStamp = function() {
 try {
   LOGGER.remove(LOGGER.transports.Console);
   LOGGER.add(LOGGER.transports.Console, {
-    level:     'warn',
+    level:     'error',
     colorize:  true,
     json:      false,
     timestamp: getTimeStamp,
-    stderrLevels: [ 'error' ] // Which levels to send to stderr
-  });
-  LOGGER.add(LOGGER.transports.File, {
-    level:    'warn',
-    filename: 'npg_ranger.winston.log',
-    json:      false,
-    timestamp: getTimeStamp,
-    maxsize:   10 * 1000 * 1000,
-    maxFiles:  20
+    stderrLevels: [ 'error', 'warn', 'info', 'verbose', 'debug', 'silly' ] // Which levels to send to stderr (all)
   });
 } catch (e) {
   console.error('Error when trying to init logging with Winston');

diff --git a/test/client/highLevelClient.spec.js b/test/client/highLevelClient.spec.js
@@ -240,7 +240,7 @@ describe('Running with ranger server with a', () => {
   let startServer = ( myDone, myFail ) => {
     let serv = spawn(serverCommand, [
       '-s',
-      '-d',
+      '--loglevel=debug',
       '-n0',
       `-p${SERV_PORT}`,
       `-m${mongourl}`]);
@@ -256,7 +256,7 @@ describe('Running with ranger server with a', () => {
   it('file url', (done) => {
     let serv = startServer( done, fail );
 
-    serv.stdout.on('data', (data) => {
+    serv.stderr.on('data', (data) => {
       if (data.toString().match(/Server listening on /)) {
         // Server is listening and ready for connection
         let client = spawn('bin/client.js', [
@@ -278,7 +278,7 @@ describe('Running with ranger server with a', () => {
   it('sample url', (done) => {
     let serv = startServer( done, fail );
 
-    serv.stdout.on('data', (data) => {
+    serv.stderr.on('data', (data) => {
       if (data.toString().match(/Server listening on /)) {
         // Server is listening and ready for connection
         let client = spawn('bin/client.js', [
@@ -304,7 +304,7 @@ describe('Running with ranger server with a', () => {
   it('sample url returning vcf', (done) => {
     let serv = startServer( done, fail );
 
-    serv.stdout.on('data', (data) => {
+    serv.stderr.on('data', (data) => {
       if (data.toString().match(/Server listening on /)) {
         // Server is listening and ready for connection
         let body = '';
@@ -327,7 +327,7 @@ describe('Running with ranger server with a', () => {
   it('GA4GH url and the redirect is followed', (done) => {
     let serv = startServer( done, fail );
 
-    serv.stdout.on('data', (data) => {
+    serv.stderr.on('data', (data) => {
       if (data.toString().match(/Server listening on /)) {
         // Server is listening and ready for connection
         let client = spawn('bin/client.js', [

diff --git a/test/config.spec.js b/test/config.spec.js
@@ -113,7 +113,7 @@ describe('Listing config options', function() {
                                    hostname:          'myhost',
                                    tempdir:           '/tmp/mydir',
                                    port:              9999,
-                                   debug:             true,
+                                   loglevel:          'debug',
                                    emaildomain:       'some.com',
                                    help:              true,
                                    clustertimeout:    1,
@@ -128,9 +128,9 @@ describe('Listing config options', function() {
       'clustermaxdeaths=2',
       'clustertimeout=1',
       'configfile=undefined',
-      'debug=true',
       'emaildomain="some.com"',
       'hostname="myhost"',
+      'loglevel="debug"',
       'mongourl="mymongourl"',
       'multiref=undefined',
       'numworkers=3',
@@ -164,7 +164,7 @@ describe('Validating CORS options', function() {
                                    hostname:  'myhost',
                                    tempdir:   '/tmp/yourdir',
                                    port:      9999,
-                                   debug:     true,
+                                   loglevel:  'debug',
                                    help:      true,
                                    anyorigin: 'true'
                                                   };});
@@ -179,7 +179,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       port - 1,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  true,
                                    originlist: ['url1','url2']
@@ -195,7 +195,7 @@ describe('Validating CORS options', function() {
                                    hostname:  'myhost',
                                    tempdir:   '/tmp/mydir',
                                    port:      9999,
-                                   debug:     true,
+                                   loglevel:  'debug',
                                    help:      true,
                                    anyorigin: true,
                                    skipauth:  false
@@ -210,7 +210,7 @@ describe('Validating CORS options', function() {
                                     hostname:    'myhost',
                                     tempdir:     '/tmp/mydir',
                                     port:        9999,
-                                    debug:       true,
+                                    loglevel:    'debug',
                                     help:        true,
                                     anyorigin:   false,
                                     originlist: 'some,urls'
@@ -223,7 +223,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  false,
                                    originlist: ['myurl']
@@ -235,7 +235,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  false,
                                    originlist: ['https://myurl']
@@ -247,7 +247,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  false,
                                    originlist: ['http://']
@@ -259,7 +259,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  false,
                                    originlist: ['http://server.com/foo']
@@ -271,7 +271,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  false,
                                    originlist: ['http://server.com/']
@@ -283,7 +283,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    anyorigin:  false,
                                    originlist: ['http://server.com//']
@@ -295,7 +295,7 @@ describe('Validating CORS options', function() {
                       hostname:   'myhost',
                       tempdir:    '/tmp/mydir',
                       port:       9999,
-                      debug:      true,
+                      loglevel:   'debug',
                       help:       true,
                       anyorigin:  false,
                       originlist: ['http://server.com/', ' ','http://server.org']
@@ -306,7 +306,7 @@ describe('Validating CORS options', function() {
                       hostname:   'myhost',
                       tempdir:    '/tmp/mydir',
                       port:       9999,
-                      debug:      true,
+                      loglevel:   'debug',
                       help:       true,
                       anyorigin:  false,
                       originlist: ['http://server.com:8080?foo=2']
@@ -317,7 +317,7 @@ describe('Validating CORS options', function() {
                       hostname:   'myhost',
                       tempdir:    '/tmp/mydir',
                       port:       9999,
-                      debug:      true,
+                      loglevel:   'debug',
                       help:       true,
                       anyorigin:  false,
                       originlist: ['http://server.com:8080?']
@@ -329,7 +329,7 @@ describe('Validating CORS options', function() {
                       hostname: 'myhost',
                       tempdir:  '/tmp/mydir',
                       port:     9999,
-                      debug:    true,
+                      loglevel: 'debug',
                       help:     true,
                       anyorigin: false,
                       originlist: ['http://localhost:9999#mttag']
@@ -340,7 +340,7 @@ describe('Validating CORS options', function() {
                       hostname:   'myhost',
                       tempdir:    '/tmp/mydir',
                       port:       9999,
-                      debug:      true,
+                      loglevel:   'debug',
                       help:       true,
                       anyorigin:  false,
                       originlist: ['http://server.com:9999#']
@@ -352,7 +352,7 @@ describe('Validating CORS options', function() {
                       hostname:  'myhost',
                       tempdir:   '/tmp/mydir',
                       port:      9999,
-                      debug:     true,
+                      loglevel:  'debug',
                       help:      true,
                       anyorigin: false,
                      originlist: ['http://server.com:9999/#tag']
@@ -365,7 +365,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    originlist: ['http://my.com']
                                   };});
@@ -378,7 +378,7 @@ describe('Validating CORS options', function() {
       hostname:   'myhost',
       tempdir:    '/tmp/mydir',
       port:       9999,
-      debug:      true,
+      loglevel:   'debug',
       help:       true,
       originlist: ['http://my.com:80','http://your.org']
                                   };});
@@ -390,7 +390,7 @@ describe('Validating CORS options', function() {
       hostname:   'myhost',
       tempdir:    '/tmp/mydir',
       port:       9999,
-      debug:      true,
+      loglevel:   'debug',
       help:       true,
       originlist: ['http://my.com:80','','http://your.org']
                                   };});
@@ -401,7 +401,7 @@ describe('Validating CORS options', function() {
                                    hostname:   'myhost',
                                    tempdir:    '/tmp/mydir',
                                    port:       9999,
-                                   debug:      true,
+                                   loglevel:   'debug',
                                    help:       true,
                                    originlist: []
                                   };});
@@ -417,7 +417,7 @@ describe('Secure server options', () => {
       mongourl:   'mymongourl',
       hostname:   'myhost',
       port:       9999,
-      debug:      true,
+      loglevel:   'debug',
       help:       true
     };
   });

diff --git a/test/server/bin_server.spec.js b/test/server/bin_server.spec.js
@@ -256,7 +256,7 @@ describe('Sockets are cleaned', () => {
       let socketPath = `${tmp_dir}/${socketName}`;
       fse.close(fse.openSync(socketPath, 'w'));
       child = spawn(serverCommand,[
-        '-d',
+        '--loglevel=debug',
         `-mmongodb://localhost:${PORT}`,
         '-k2', '-l1', // Max 2 deaths in 1 second
         '-n', `${numWorkers}`,
@@ -279,7 +279,7 @@ describe('Sockets are cleaned', () => {
       expect(err).toBeDefined();
     });
     child = spawn(serverCommand,[
-      '-d',
+      '--loglevel=debug',
       `-mmongodb://localhost:${PORT}`,
       `-n0`,
       '-p', `${socketPath}`]
@@ -311,7 +311,7 @@ describe('Sockets are cleaned', () => {
       expect(err).toBeDefined();
     });
     child = spawn(serverCommand,[
-      '-d',
+      '--loglevel=debug',
       `-mmongodb://localhost:${PORT}`,
       `-n5`,
       '-p', `${socketPath}`]