Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bunch of commits from local #7

Merged
merged 8 commits into from
Jun 26, 2013
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions .gitignore
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
npm-debug.log
node_modules
.DS_Store
72 changes: 62 additions & 10 deletions README.md
Original file line number Diff line number Diff line change
@@ -1,15 +1,67 @@
Installation
============
# winston-tagged-http-logger

npm install winston-tagged-http-logger
Pipes events from a node HTTP server (vanilla OR express!) to a
[tagged-logger](http://bitbucket.org/maghoff/tagged-logger)
for [winston](https://github.com/flatiron/winston).

Usage
=====
## Install me!

For this example to work, you need to `npm install winston tagged-logger winston-tagged-http-logger`.
```
npm install winston-tagged-http-logger
```

var server = require('http').createServer();
var log = new (require('tagged-logger'))(require('winston'), []);
require('winston-tagged-http-logger')(server, log);
## Example

// From now on, important events from `server` will be logged to `log`
This will create a new [winston](https://github.com/flatiron/winston)
[logger](https://github.com/flatiron/winston#instantiating-your-own-logger) and
a new [tagged-logger](https://bitbucket.org/maghoff/tagged-logger/), and use
a [tagged-console-target](https://bitbucket.org/maghoff/tagged-console-target)
to write the output to the console in all the colours of the rainbow.

```javascript
var server = require('http').createServer();

// create our winston logger
var winston = require('winston');
var winstonLogger = new winston.Logger();

// create a transport so our logs have somewhere to go
var TaggedConsoleTarget = require('tagged-console-target');
winston.add(new TaggedConsoleTarget());

// make a new tagged logger to generate tagged log messages
var TaggedLogger = require('tagged-logger');
var logger = new TaggedLogger(winstonLogger, ['my amazing server']);

// Use this module to pipe the events from an http server to the logger
require('winston-tagged-http-logger')(server, log);

// All done! Events from `server` are now being piped to our `logger`!
```

## What events are logged?

* When the server starts running, showing the
host and port that the server started on.
* When a request is responded to, the client, path, status code, method and
response time are logged.

## What is the format of the logs?

Why, take a look! Here's an example of a log:

```
19:35:53.255 2013-06-26 Wednesday
19:35:53.589 [kvass, http] Listening on 0.0.0.0:9506
19:36:06.359 [kvass, http, 127.0.0.1:50230] GET /user/active 200 12ms
```

Broken down, these are the parts of a request log:

* `19:36:06.359` the time on the server at which the request was received
* `[kvass, http,` tags that have been assigned to this logger
* `127.0.0.1:50230]` a tag representing the origin of the request
* `GET` the request method
* `/user/active` the requested path
* `200` the response status code
* `12ms` the time it took to respond to the request
14 changes: 8 additions & 6 deletions index.js
Original file line number Diff line number Diff line change
@@ -1,17 +1,19 @@
module.exports = function (app, log) {
function loggerMiddleware(req, res, next) {
var startTime = new Date();
var url = req.url;
var method = req.method;

var end = res.end;
res.end = function(chunk, encoding) {
res.end = end;
res.end(chunk, encoding);
function writeLog() {
var socketLog = log.createSublogger(
req.socket.remoteAddress + ":" + req.socket.remotePort);
socketLog.info([
req.method, req.url, res.statusCode, (new Date() - startTime) + "ms "
method, url, res.statusCode, (new Date() - startTime) + "ms "
].join(' '));
};
}

if (res.finished) writeLog()
else res.on('finish', writeLog);

if (next) next();
};
Expand Down
16 changes: 15 additions & 1 deletion package.json
Original file line number Diff line number Diff line change
Expand Up @@ -3,10 +3,24 @@
"version": "1.0.1",
"description": "Sets up logging to a TaggedLogger for important http.Server events",
"main": "index.js",
"scripts": {
"test": "./node_modules/mocha/bin/mocha -R spec"
},
"repository": {
"type": "git",
"url": "https://github.com/brikteknologier/winston-tagged-http-logger.git"
},
"author": "Magnus Hoff <magnus.hoff@brik.no>",
"license": "BSD"
"license": "BSD",
"peerDependencies": {
"winston": "~0.7.2",
"tagged-logger": "~1.0.0"
},
"devDependencies": {
"tagged-logger": "~1.0.0",
"mocha": "~1.11.0",
"winston": "~0.7.2",
"supertest": "~0.7.0",
"express": "~3.2.6"
}
}
127 changes: 127 additions & 0 deletions test/logger.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,127 @@
var http = require('http');
var wthl = require('../');
var winston = require('winston');
var TaggedLogger = require('tagged-logger');
var assert = require('assert');
var express = require('express');
var request = require('supertest');

describe('Tagged http logger', function() {
var logger;
var transport;
beforeEach(function() {
transport = new winston.transports.Memory();
var baseLogger = new winston.Logger({transports: [transport]});
logger = new TaggedLogger(baseLogger, []);
});

describe('Vanilla HTTP server', function() {
var server;
beforeEach(function() {
server = http.createServer(function(req, res) {
if (req.url == '/sync') {
res.end();
} else if (req.url == '/async') {
setTimeout(function() { res.statusCode = 201; res.end() }, 10);
}
});
wthl(server, logger);
});

it('should log the http listen event', function(done) {
server.listen(0, function() {
process.nextTick(function() {
assert(transport.writeOutput.length == 1);
assert(transport.writeOutput[0].match(/listening/gi));
done();
});
});
});

it('should log a request', function(done) {
server.listen(0, function() {
request(server).get('/sync').end(function(err, res) {
assert(transport.writeOutput.length == 2);
assert(transport.writeOutput[1].match(/get/gi));
assert(transport.writeOutput[1].match(/sync/gi));
assert(transport.writeOutput[1].match(/200/g));
done();
});
});
});

it('should log an async request', function(done) {
server.listen(0, function() {
request(server).get('/async').end(function(err, res) {
assert(transport.writeOutput.length == 2);
assert(transport.writeOutput[1].match(/get/gi));
assert(transport.writeOutput[1].match(/async/gi));
assert(transport.writeOutput[1].match(/201/g));
done();
});
});
});
});

describe('express http server', function() {
var server;
beforeEach(function() {
server = express();
wthl(server, logger);
server.get('/sync', function(req, res) { res.end() });
server.get('/async', function(req, res) {
setTimeout(function() { res.statusCode = 201; res.end() }, 10);
});
});
it('should log the http listen event', function(done) {
server.listen(0, function() {
process.nextTick(function() {
assert(transport.writeOutput.length == 1);
assert(transport.writeOutput[0].match(/listening/gi));
done();
});
});
});

it('should log a request', function(done) {
server.listen(0, function() {
request(server).get('/sync').end(function(err, res) {
assert(transport.writeOutput.length == 2);
assert(transport.writeOutput[1].match(/get/gi));
assert(transport.writeOutput[1].match(/sync/gi));
assert(transport.writeOutput[1].match(/200/g));
done();
});
});
});

it('should log an async request', function(done) {
server.listen(0, function() {
request(server).get('/async').end(function(err, res) {
assert(transport.writeOutput.length == 2);
assert(transport.writeOutput[1].match(/get/gi));
assert(transport.writeOutput[1].match(/async/gi));
assert(transport.writeOutput[1].match(/201/g));
done();
});
});
});

it('should handle nested express servers', function(done) {
var nestedServer = express();
nestedServer.get('/thing', function(req, res) { res.end() });
server.use('/nested', nestedServer);

server.listen(0, function() {
request(server).get('/nested/thing').end(function(err, res) {
assert(transport.writeOutput.length == 2);
assert(transport.writeOutput[1].match(/get/gi));
assert(transport.writeOutput[1].match(/\/nested\/thing/gi));
assert(transport.writeOutput[1].match(/200/g));
done();
});
});
});
});
});