haraka / Haraka

A fast, highly extensible, and event driven SMTP server
https://haraka.github.io
MIT License
5.02k stars 662 forks source link

Logging #94

Closed smfreegard closed 12 years ago

smfreegard commented 12 years ago

Since commit '28373500cb77eece0fc51e7959b1f68997925b57' - log output to the console is much worse:

For example:

[CRIT] SyntaxError: Unexpected end of input0[ 'SyntaxError: Unexpected end of input',\n ' at Object._load_and_compile_plugin (/root/Haraka/plugins.js:161:12)',\n ' at /root/Haraka/plugins.js:121:26',\n ' at Array.map (native)',\n ' at Object.load_plugins (/root/Haraka/plugins.js:115:39)',\n ' at Object.createServer (/root/Haraka/server.js:60:13)',\n ' at Object. (/root/Haraka/haraka.js:39:8)',\n ' at Module._compile (module.js:402:26)',\n ' at Object..js (module.js:408:10)',\n ' at Module.load (module.js:334:31)',\n ' at Function._load (module.js:293:12)' ] [CRIT] at Object._load_and_compile_plugin (/root/Haraka/plugins.js:161:12)1[ 'SyntaxError: Unexpected end of input',\n ' at Object._load_and_compile_plugin (/root/Haraka/plugins.js:161:12)',\n ' at /root/Haraka/plugins.js:121:26',\n ' at Array.map (native)',\n ' at Object.load_plugins (/root/Haraka/plugins.js:115:39)',\n ' at Object.createServer (/root/Haraka/server.js:60:13)',\n ' at Object. (/root/Haraka/haraka.js:39:8)',\n ' at Module._compile (module.js:402:26)',\n ' at Object..js (module.js:408:10)',\n ' at Module.load (module.js:334:31)',\n ' at Function._load (module.js:293:12)' ]

The intent of the previous patch was to remove carriage returns from messing up the syslog output (as syslog on Linux doesn't handle this well).

How about changing line 33 of logger.js to:

data.replace(/\r/g, '');

It should then be up to the individual log plugin as to whether to filter LF's into \n or not (syslog handled LF's without issue).

With this modification; my console log output is back to normal:

[CRIT] at Function._load (module.js:293:12)10[ 'SyntaxError: Unexpected end of input', ' at Object._load_and_compile_plugin (/root/Haraka/plugins.js:161:12)', ' at /root/Haraka/plugins.js:121:26', ' at Array.map (native)', ' at Object.load_plugins (/root/Haraka/plugins.js:115:39)', ' at Object.createServer (/root/Haraka/server.js:60:13)', ' at Object. (/root/Haraka/haraka.js:39:8)', ' at Module._compile (module.js:402:26)', ' at Object..js (module.js:408:10)', ' at Module.load (module.js:334:31)', ' at Function._load (module.js:293:12)' ]

baudehlo commented 12 years ago

Interestingly that one comes because of the global process.on('uncaughtException') which I'm thinking of getting rid of anyway...

smfreegard commented 12 years ago

Ok - but my point was shouldn't it be up to the log plugin to strip LF's or not?

As for getting rid of the uncaughtException process event; for plugins with syntax errors - it's not very useful as vm.runInNewContextContext() exceptions do not show the file and line number of the actual error despite 'name' being provided to it.

I've just modified my plugins.js to this:

try {
    vm.runInNewContext(code, sandbox, name);
}
catch (err) {
    logger.logcrit('Loading plugin ' + name + ' failed: ', err.message);
    if (config.get('smtp.ini', 'nolog', 'ini').main.ignore_bad_plugins) {
        return;
    }
    else {
        throw 'plugin_error';
    }
}

That provides much briefer output on plugin errors and is no less useful than a full stack trace:

[root@vm3 Haraka]# node haraka.js [DEBUG] no cluster available, running single-process Starting up Haraka version 0.9.0 [INFO] Loading plugins [INFO] Loading plugin: stats [CRIT] Loading plugin stats failed: Unexpected token . [CRIT] Caught exception: plugin_error [CRIT] Server not ready yet. Stopping.

justinpincar commented 12 years ago

+1. No line breaks makes errors extremely difficult to read.

baudehlo commented 12 years ago

Please try 1.0.0. Closing this issue for now.