Refactor logging to provide common logger from LoggerAdapter

[flovilmart]

• Refactors logger into the WinstonLoggerAdapter and WinstonLogger
• Exposes the loggerController, instead of the adapter
• adds silent option to silent all console logs (from command line or code)
• adds logLevel / PARSE_SERVER_LOG_LEVEL option for setting the log level
• Custom logger adapters will be passed logLevel, logsFolder, silent, verbose, jsonLogs options
• Custom loggers don't require the query function anymore to allow fan out loggers
• Custom loggers require only log to load properly
• LoggerController exposes more methods (cf: winston and npm))

[codecov-io]

Current coverage is 92.66% (diff: 95.02%)

Merging #2478 into master will increase coverage by 0.19%

@@             master      #2478   diff @@
==========================================
  Files            93         94     +1   
  Lines         10629      10709    +80   
  Methods        1310       1315     +5   
  Messages          0          0          
  Branches       1728       1740    +12   
==========================================
+ Hits           9829       9924    +95   
+ Misses          800        785    -15   
  Partials          0          0          

Powered by Codecov. Last update 6e0a25d...f2c4770

[steven-supersolid]

Should we include an empty get logger() here?

[acinader]

log.logger.info seems unfortunate. any way we can do without that level indirection?

[acinader]

https://github.com/ParsePlatform/parse-server/blob/fa736f1df7b6a4f6dbc3f08b2f9db8711de23694/src/ParseServer.js#L181

configured for silly?

I'd suggest we just implement the full sweet? debug is useful. https://github.com/winstonjs/winston#logging-levels

[flovilmart]

agreed.

In winston, the 1st argument of log is the level you want to log to.

As for silly, I can down to verbose as we don't log higher

[acinader]

remove

[flovilmart]

@acinader, @steven-supersolid, @TylerBrock / @spenthil I'm good with the changes on that PR. I you guys want to review, feel free.

[acinader]

output to console or don't catch?

[flovilmart]

May fail if the folder exists, so we just let go

[acinader]

I'll test it against https://github.com/acinader/parse-aws-firehose-logger-adapter/blob/master/README.md tomorrow morning.

[steven-supersolid]

Should we load earlier and assign logging at the same time so that any initialisation logs can use the custom logger and options too?

[flovilmart]

Not sure it would change much, but we could.

[acinader]

@flovilmart

my testing is not going well :).

I removed all logger configuration from my startup of parse-server.

Logs are getting written to ./logs as expected.

I am not able to use the logger to log.

in my cloud code I am trying to include logger like so:

const logger = require('parse-server').logger

but it isn't working (undefined).

How am I supposed to access the logger for writing?

[flovilmart]

In cloud code the logger is exposed through req.log. You should use that one.

Also cloud code modules are loaded first, we could try to load them last.

I just tested also:

var logger = require('../../src').logger;
Parse.Cloud.define('cloudCodeInFile', (req, res) => {
  console.log('logger:', logger);
  res.success('It is possible to define cloud code in a file.');
});

In the snipped the logger is not undefined as is.

Moving cloud code initialization last would let us do:

var logger = require('../../src').logger;
console.log('logger:', logger); // OK
Parse.Cloud.define('cloudCodeInFile', (req, res) => {
  console.log('logger:', logger); // OK!
  res.success('It is possible to define cloud code in a file.');
});

[acinader]

So two other issues I'm not sure how to work around:

• I can no longer use the logger in my index:

const conf = require('config');
const express = require('express');
const ParseServer = require('parse-server').ParseServer;
const logger = require('parse-server').logger;
const playlist = require('./routes/playlist');
const sns = require('./routes/sns');
const app = express();
const api = new ParseServer(conf.parseServerOptions);

const port = conf.parseServerOptions.port;

app.use('/parse', api);

app.get('/ping', (req, res) => {
  res.send('pong');
});

app.get('/playlist/:hlsVersion/:storyId', playlist.getPlaylist);

app.post('/receiveSnsMessage', sns.receive);

app.listen(port, () => {
  logger.info(`parse-server running on port ${port}.`);
});

module.exports = app;

• I am unable to configure the logger in my conf files. I'm using https://www.npmjs.com/package/config for config and my logger config looks like this:

....
loggerAdapter: defer(cfg => new FirehoseLoggerAdapter(cfg.firehoseAdapterOptions)),
....
firehoseAdapterOptions: {
    streamName: 'epic-logs',
    level: 'info',
  },
...

but it fails when trying to require WinstonLogger cause the defaults aren't set yet.

I'm trying to grok what is going on, but the pattern your using for defining the exports in ./logger.js are going over my head :(

[flovilmart]

Try do the require const logger = ParseServer.logger; AFTER parse server init, before, it's not materialized as not instantiated :)

For your adapter: try:

{
  loggerAdapter: {
    module: 'firehose-logger-adapter-module'
    options: {} 
  }
}

The adapter loader should be able to handle it, and load your module correctly.
I'm not sure what would cause the defaults not to be set (circular references maybe?) Can you provide the full trace?

[acinader]

wow, i'm just batting zero today ;)

in my index, i tried:

const api = new ParseServer(conf.parseServerOptions);
const logger = api.logger;

but logger is still undefined.

and on the adapterLoader, I tried:

    loggerAdapter: {
      module: 'parse-aws-firehose-logger-adapter',
      options: {
        streamName: 'epic-dev-logs',
        level: 'info',
      },

but it gives me:

Error: Cannot find module 'parse-aws-firehose-logger-adapter'
    at Function.Module._resolveFilename (module.js:440:15)
    at Function.Module._load (module.js:388:25)
    at Module.require (module.js:468:17)

the module is listed as a dependency in my package.json

✗ ls -d node_modules/parse-aws-firehose-logger-adapter 
node_modules/parse-aws-firehose-logger-adapter

[flovilmart]

const api = new ParseServer(conf.parseServerOptions);
const logger = api.logger;

The logger is not exposed here.

const ParseServer = require('parse-server').ParseServer;
const api = new ParseServer(conf.parseServerOptions);
const logger = require('parse-server').logger;

Does that do the trick?

For the other issue, I'm not sure why the adapter wouldn't load correctly :/ That's pretty odd...

[acinader]

yes, your incantation works in index.

also I can no include the logger in cloud code with

const logger = require('parse-server').logger.

now works again in cloud code.

I'm assuming that my logging adapter isn't loading because of how I have defined/exported it, so working on that.

[flovilmart]

@acinader just tested and it seems that we can load from a module from NPM. that's odd (or something that I don't take into account)

[ghost]

@flovilmart updated the pull request.

[ghost]

@flovilmart updated the pull request.

[jpv123]

Any guide for begginers (like me) to setup this correctly? I'm a little bit tired of the big ammount of logging. It's nearly impossible to get the main info that I need from the logs in this moment

[acinader]

@jpv123 you can keep an eye on #2501

I'm going to try and make the logging just like it was on parse.com. I intend to get to it this week (unless someone beats me to it).

[sprabs]

Sorry, for the trouble, but I'm pretty confused at this point with logging on parse-server and things have changed a lot without any update to the wiki, so I'm not sure how to proceed. I thought this would be an appropriate place to comment since I noticed a back-and-forth about perhaps some similar confusion.

Even with verbose set to true, I'm not seeing any logs (after the series of changes to parse-server logs changes). I'm running my parse server on AWS Elastic Beanstalk.

My index.js looks something like this:

var logger = require('parse-server/lib/Adapters/Logger/FileLoggerAdapter').FileLoggerAdapter;

// ...
var api = new ParseServer({
  databaseURI: databaseUri || 'mongodb://localhost:27017/dev',
  cloud: process.env.CLOUD_CODE_MAIN || __dirname + '/cloud/main.js',
  appId: process.env.APP_ID || 'myAppId',
  masterKey: process.env.MASTER_KEY || '', //Add your master key here. Keep it secret!
  serverURL: process.env.SERVER_URL || 'http://localhost:1337',  // Don't forget to change to https if needed
  loggerAdapter: new logger({ logsFolder: './' })
});

What do I need to fix to get logging back?

[flovilmart]

You don't have to pass loggerAdapter.
Just set logsFolder and verbose upon initialization of the ParseServer object

[sprabs]

After following this thread, I tried this in my index.js:

var express = require('express');
var ParseServer = require('parse-server').ParseServer;

var databaseUri = process.env.DATABASE_URI || process.env.MONGOLAB_URI;

if (!databaseUri) {
  console.log('DATABASE_URI not specified, falling back to localhost.');
}

var WinstonLoggerAdapter = require('parse-server/lib/Adapters/Logger/WinstonLoggerAdapter');
var api = new ParseServer({
  databaseURI: databaseUri,
  appId: process.env.APP_ID || 'myAppId',
  masterKey: process.env.MASTER_KEY || '', //Add your master key here. Keep it secret!
  serverURL: process.env.SERVER_URL || 'http://localhost:1337',  // Don't forget to change to https if needed
  webhookKey: process.env.WEBHOOK_KEY || 'hook',
  push: {
    android: {
        senderId: process.env.GCM_SENDER_ID,
        apiKey: process.env.GCM_API_KEY
    },
    ios: {
        pfx: 'something.p12',
        bundleId: 'something.dev',
        production: false
    }
  },
  verbose: process.env.VERBOSE,
  logsFolder: process.env.PARSE_SERVER_LOGS_FOLDER,
  loggerAdapter: {
      module: WinstonLoggerAdapter,
      options: {
        level: 'info',
        jsonLogs: true,
      }
  },
  cloud: process.env.CLOUD_CODE_MAIN || __dirname + '/cloud/main.js'
});

var logger = require('parse-server').logger;

var app = express();

// Serve the Parse API on the /parse URL prefix
var mountPath = process.env.PARSE_MOUNT || '/1';
app.use(mountPath, api);

// Parse Server plays nicely with the rest of your web routes
app.get('/', function(req, res) {
  res.status(200).send('I dream of being a web site.');
});

var port = process.env.PORT || 1337;
app.listen(port, function() {
    console.log('parse-server running on port ' + port + '.');
});

And I added this at the top of my main.js:

var logger = require('../../src').logger;
console.log('logger:', logger); // OK

I am getting this error:

> node index.js

/var/app/current/node_modules/parse-server/lib/Controllers/AdaptableController.js:74
        throw new Error("Adapter prototype don't match expected prototype", adapter, mismatches);
        ^

Error: Adapter prototype don't match expected prototype
    at LoggerController.validateAdapter (/var/app/current/node_modules/parse-server/lib/Controllers/AdaptableController.js:74:15)
    at LoggerController.set (/var/app/current/node_modules/parse-server/lib/Controllers/AdaptableController.js:80:12)
    at LoggerController.AdaptableController (/var/app/current/node_modules/parse-server/lib/Controllers/AdaptableController.js:39:18)
    at new LoggerController (/var/app/current/node_modules/parse-server/lib/Controllers/LoggerController.js:50:85)
    at new ParseServer (/var/app/current/node_modules/parse-server/lib/ParseServer.js:266:28)
    at new _ParseServer (/var/app/current/node_modules/parse-server/lib/index.js:36:16)
    at Object.<anonymous> (/var/app/current/index.js:16:11)
    at Module._compile (module.js:409:26)
    at Object.Module._extensions..js (module.js:416:10)
    at Module.load (module.js:343:32)

What am I doing wrong? Also, for the path of logsFolder, is it an absolute or relative path?

[flovilmart]

Absolute or relative it doesn't matter. You can't specify both logsFolder/VERBOSE AND the loggerAdapter. Moreover, if you want verbose logs, the level should be 'verbose'

Setting verbose and logsFolder, will be passed to the default adapter which is the WinstonLoggerAdapter so you don't need to pass the loggerAdapter option.

If you still want to pass the loggerAdapter option, remove logsFolder and verbose. Either do new WinstonLoggerAdapter(options) or

loggerAdapter: { module: pathToWinstonAdapter,
options: optionsForLogger }

I don't recommend the second way as we don't guarantee the path to the adapter will stay, nor the adapter will stay part of the core of parse-server the same way we removed the files adapters and push adapters.

I don't consider this a breaking change as those modules are internal and not supposed to be used outside of the package.

[sprabs]

Thank you for the feedback. That was very helpful. I'm now trying this (below), but I still see no logs. The PARSE_SERVER_LOGS_FOLDER I set is /var/log/nodejs (that's where I had been seeing logs before they disappeared with the new parse-server changes). Do you think that path is invalid? Is there something I also need to add to the Cloud Code? Previously, I was able to see all inputs and outputs when I set verbose to true. Now, I don't see anything.

Code:

var express = require('express');
var ParseServer = require('parse-server').ParseServer;

var databaseUri = process.env.DATABASE_URI || process.env.MONGOLAB_URI;

if (!databaseUri) {
  console.log('DATABASE_URI not specified, falling back to localhost.');
}

var logger = require('parse-server/lib/Adapters/Logger/FileLoggerAdapter').FileLoggerAdapter;

var api = new ParseServer({
  databaseURI: databaseUri,
  appId: process.env.APP_ID || 'myAppId',
  cloud: process.env.CLOUD_CODE_MAIN || __dirname + '/cloud/main.js',
  masterKey: process.env.MASTER_KEY || '', //Add your master key here. Keep it secret!
  serverURL: process.env.SERVER_URL || 'http://localhost:1337',  // Don't forget to change to https if needed
  webhookKey: process.env.WEBHOOK_KEY || 'hook',
  push: {
    android: {
        senderId: process.env.GCM_SENDER_ID,
        apiKey: process.env.GCM_API_KEY
    },
    ios: {
        pfx: './something.p12',
        bundleId: 'something.dev',
        production: false
    }
  },
  verbose: true,
  logsFolder: process.env.PARSE_SERVER_LOGS_FOLDER
});
// Client-keys like the javascript key or the .NET key are not necessary with parse-server
// If you wish you require them, you can set them as options in the initialization above:
// javascriptKey, restAPIKey, dotNetKey, clientKey

var app = express();

// Serve the Parse API on the /parse URL prefix
var mountPath = process.env.PARSE_MOUNT || '/1';
app.use(mountPath, api);

// Parse Server plays nicely with the rest of your web routes
app.get('/', function(req, res) {
  res.status(200).send('I dream of being a web site.');
});

var port = process.env.PORT || 1337;
app.listen(port, function() {
    console.log('parse-server running on port ' + port + '.');
});

Thank you so much for your help. I've been trying to debug this for some time, and I really appreciate it.

[flovilmart]

Setting the logsFolder option should set the dirname option of the Winston logger.

When running unit tests, we use that option to output the logs to the test_logs folder. When passing no options it should log to the ./logs folder. Does that work?

[sprabs]

Thanks @flovilmart! I now see the two folders: parse-server.err.2016-09-05, parse-server.info.2016-09-05

However, the error folder seems to be displaying even non-errors (with perfectly fine responses). Why do you think that's happening. Also, obviously, verbose = true is crazy. What log level do you recommend for debugging purposes and also in production and where do you set it?

[flovilmart]

There is a bug in the current version that makes both info and error log the same. This will be fixed in the next release

[flovilmart]

You should be able to set the level with the logLevel option directly on parse-server. Info level should be fine in production, you'll mostly have whatever was logged on good ol parse.com namely Cloud Code triggers and functions.

VERBOSE is useful when you need to trace particular request/responses. Debug in only used with the Postgres Adapter to log all DB queries, unused with the mongo adapter.

[sprabs]

Ah, okay. I'm seeing the same issue on the dashboard as well (info and error being the same). Since I don't have the loggerAdapter line, how do I set a logLevel option of info in index.js?

Also, this is somewhat related: I did a pull of the latest parse server code and am installing it locally on my machine. When I do an npm install and deploy it, my parse server bugs out and crashes (complaining of an npm issue). I'm not sure what changed that would cause this.

[flovilmart]

Set logLevel directly in the options to create the ParseServer object. When in doubt look at the source code.

For the other thing, you should probably open another issue, as this as already turned into a discussion onto an issue that's already closed.

[sprabs]

Thanks, @flovilmart.

logLevel didn't seem to work for me, but I'll try to check the documentation and see what I may be doing wrong. The iOS and Android clients still aren't getting error messages returned. I'm not sure if there's something else we need to set for that to make it the same as parse.com. When there are parse errors that are not javascript errors, the client doesn't get any kind of error back.

For the other problem I am having, I've filed an issue: #2666

[flovilmart]

errors like object not found are not returned to the clients???

[sprabs]

No, instead it just has internal default errors from the SDK. For instance, for iOS, it can be something like: Error Domain=NSCocoaErrorDomain Code=3840 "No value." ...

[flovilmart]

that doesn't make any sense...

[sprabs]

Yeah, I agree. I'm really confused. Something seems to have broken in the last few weeks that is really making debugging anything impossible with parse-server. What do you suggest I check?

[flovilmart]

running with VERBOSE=1 and make sure whatever gets in / out is working correctly. I don't believe discussing on a PR that's been closed for a month is also the best way to convert issues. So please, open a proper issue, with the relevant informations to your issues.