From 87da62bca27314d2eaaced29c247e9da964ef6c2 Mon Sep 17 00:00:00 2001
From: Arthur Cinader <700572+acinader@users.noreply.github.com>
Date: Thu, 9 May 2019 12:58:54 -0700
Subject: [PATCH] Logger: Fix timestamp and format (#5571)

* remove no-op config of logger

* add a test to check on the timestamp

* add a test to verify that we
get non json console loggging by default

* configure transports to include
timestamps in files

* Add failing test to confirm that WinstonLoggerAdapter
is not filtering on level.

* actually fix the test to refelect the facth that this isn't the problem

* Remove bogus date ranges that are now failing
becuase we have timestamps.
---
 spec/Logger.spec.js                  | 30 +++++++++++++++++++++++++++
 spec/LoggerController.spec.js        |  6 ------
 spec/WinstonLoggerAdapter.spec.js    | 16 ++++++++++++++
 src/Adapters/Logger/WinstonLogger.js | 31 ++++++++++++++--------------
 4 files changed, 62 insertions(+), 21 deletions(-)

diff --git a/spec/Logger.spec.js b/spec/Logger.spec.js
index ad387ba0..1fbfe541 100644
--- a/spec/Logger.spec.js
+++ b/spec/Logger.spec.js
@@ -39,6 +39,36 @@ describe('WinstonLogger', () => {
     });
   });
 
+  it('should have a timestamp', done => {
+    logging.logger.info('hi');
+    logging.logger.query({ limit: 1 }, (err, results) => {
+      if (err) {
+        done.fail(err);
+      }
+      expect(results['parse-server'][0].timestamp).toBeDefined();
+      done();
+    });
+  });
+
+  it('console should not be json', done => {
+    // Force console transport
+    reconfigureServer({
+      logsFolder: null,
+      silent: false,
+    })
+      .then(() => {
+        spyOn(process.stdout, 'write');
+        logging.logger.info('hi', { key: 'value' });
+        expect(process.stdout.write).toHaveBeenCalled();
+        const firstLog = process.stdout.write.calls.first().args[0];
+        expect(firstLog).toEqual('info: hi {"key":"value"}' + '\n');
+        return reconfigureServer();
+      })
+      .then(() => {
+        done();
+      });
+  });
+
   it('should enable JSON logs', done => {
     // Force console transport
     reconfigureServer({
diff --git a/spec/LoggerController.spec.js b/spec/LoggerController.spec.js
index 2e975845..a98e7d63 100644
--- a/spec/LoggerController.spec.js
+++ b/spec/LoggerController.spec.js
@@ -66,10 +66,7 @@ describe('LoggerController', () => {
   });
 
   it('can process an ascending query without throwing', done => {
-    // Make mock request
     const query = {
-      from: '2016-01-01Z00:00:00',
-      until: '2016-01-01Z00:00:00',
       size: 5,
       order: 'asc',
       level: 'error',
@@ -114,10 +111,7 @@ describe('LoggerController', () => {
   });
 
   it('can process a descending query without throwing', done => {
-    // Make mock request
     const query = {
-      from: '2016-01-01Z00:00:00',
-      until: '2016-01-01Z00:00:00',
       size: 5,
       order: 'desc',
       level: 'error',
diff --git a/spec/WinstonLoggerAdapter.spec.js b/spec/WinstonLoggerAdapter.spec.js
index 3a358fd3..f6ac3a49 100644
--- a/spec/WinstonLoggerAdapter.spec.js
+++ b/spec/WinstonLoggerAdapter.spec.js
@@ -66,6 +66,22 @@ describe('error logs', () => {
       }
     );
   });
+
+  it('Should filter on query', done => {
+    const winstonLoggerAdapter = new WinstonLoggerAdapter();
+    winstonLoggerAdapter.log('error', 'testing error logs');
+    winstonLoggerAdapter.query(
+      {
+        from: new Date(Date.now() - 500),
+        size: 100,
+        level: 'error',
+      },
+      results => {
+        expect(results.filter(e => e.level !== 'error').length).toBe(0);
+        done();
+      }
+    );
+  });
 });
 
 describe('verbose logs', () => {
diff --git a/src/Adapters/Logger/WinstonLogger.js b/src/Adapters/Logger/WinstonLogger.js
index ea976889..8968e498 100644
--- a/src/Adapters/Logger/WinstonLogger.js
+++ b/src/Adapters/Logger/WinstonLogger.js
@@ -1,4 +1,4 @@
-import winston from 'winston';
+import winston, { format } from 'winston';
 import fs from 'fs';
 import path from 'path';
 import DailyRotateFile from 'winston-daily-rotate-file';
@@ -19,9 +19,9 @@ function configureTransports(options) {
           {
             filename: 'parse-server.info',
             json: true,
+            format: format.combine(format.timestamp(), format.json()),
           },
-          options,
-          { timestamp: true }
+          options
         )
       );
       parseServer.name = 'parse-server';
@@ -32,27 +32,28 @@ function configureTransports(options) {
           {
             filename: 'parse-server.err',
             json: true,
+            format: format.combine(format.timestamp(), format.json()),
           },
           options,
-          { level: 'error', timestamp: true }
+          { level: 'error' }
         )
       );
       parseServerError.name = 'parse-server-error';
       transports.push(parseServerError);
     }
 
-    transports.push(
-      new winston.transports.Console(
-        Object.assign(
-          {
-            colorize: true,
-            name: 'console',
-            silent,
-          },
-          options
-        )
-      )
+    const consoleFormat = options.json ? format.json() : format.simple();
+    const consoleOptions = Object.assign(
+      {
+        colorize: true,
+        name: 'console',
+        silent,
+        format: consoleFormat,
+      },
+      options
     );
+
+    transports.push(new winston.transports.Console(consoleOptions));
   }
 
   logger.configure({