minimum viable product

.eslintrc.yml

@@ -0,0 +1,3 @@
+extends: fullstack
+rules:
+  semi: [1, never]

.gitignore

@@ -0,0 +1,23 @@
+# installed packages (better: `npm install` / `bower install`)
+node_modules
+bower_components
+
+# OS-generated files
+.DS_Store
+.DS_Store?
+._*
+.Spotlight-V100
+.Trashes
+ehthumbs.db
+Thumbs.db
+
+# Logs and databases
+*.log
+*.sqlite
+
+# Vim swap files
+*.sw?
+
+# IDE files
+.idea
+.vscode

LICENSE

@@ -0,0 +1,21 @@
+The MIT License (MIT)
+
+Copyright (c) 2016 Gabriel Lebec
+
+Permission is hereby granted, free of charge, to any person obtaining a copy
+of this software and associated documentation files (the "Software"), to deal
+in the Software without restriction, including without limitation the rights
+to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+copies of the Software, and to permit persons to whom the Software is
+furnished to do so, subject to the following conditions:
+
+The above copyright notice and this permission notice shall be included in
+all copies or substantial portions of the Software.
+
+THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+THE SOFTWARE.

README.md

@@ -0,0 +1,59 @@
+# 🏐 Volleyball
+
+### Small Express HTTP logger for debugging asynchronous requests and responses
+
+```js
+const app = require('express')()
+const volleyball = require('volleyball')
+
+app.use(volleyball)
+```
+
+Volleyball is a minimal Connect-style middleware function which logs incoming requests and outgoing responses as separate events. It optionally supports the [`debug`](https://github.com/visionmedia/debug#readme) module.
+
+## Motivation
+
+Logging HTTP cycles can be approached in several ways, each with its own drawbacks:
+
+* Log only upon **request**. Drawback: we cannot log the corresponding response, which happens later (if at all).
+* Log only upon **response**, attaching the request. Drawback A: if the server never sends a response, e.g. due to a bug, the request will not be logged either. Drawback B: two temporally distinct events are conflated, misleadingly.
+* Log both upon **request** and **response**. Drawback: it is not necessarily clear which responses are for which requests.
+
+Volleyball takes the last approach, and assigns randomly-generated ids to label request-response pairs. It is designed for student project development, teaching beginning programmers how HTTP servers and asynchronicity work. It may also be useful as a low-configuration debug tool.
+
+## Usage
+
+### `volleyball`
+
+The `volleyball` module can be used directly as demonstrated in the first example. The module defaults to using `process.stdout` for output.
+
+### `volleyball.custom(config)`
+
+A customized logging middleware can be generated by calling `custom` with a configuration object:
+
+```js
+const logger = volleyball.custom({ debug: true }) // default namespace 'http'
+// const logger = volleyball.custom({ debug: 'custom-namespace' })
+// const logger = volleyball.custom({ debug: debugInstance })
+
+app.use(logger)
+```
+
+The `debug` property logs using the [`debug`](https://github.com/visionmedia/debug#readme) module. It supports the following values:
+
+value | result
+----|----
+`true` | uses a new debug instance with a default namespace of `'http'`
+string | uses a new debug instance with a custom namespace
+function | uses any function, such as a pre-generated debug instance. Note that the function will be called with colorized strings.
+
+## Related and Alternatives
+
+For more powerful, configurable, and compatible logging needs, check out:
+
+* [debug](https://github.com/visionmedia/debug#readme)
+* [morgan](https://github.com/expressjs/morgan#readme)
+* [morgan-debug](https://github.com/ChiperSoft/morgan-debug#readme)
+* [winston](https://github.com/winstonjs/winston#readme)
+* [express-winston](https://github.com/bithavoc/express-winston#readme)
+* [node-bunyan](https://github.com/trentm/node-bunyan/#readme)

lib/id.js

@@ -0,0 +1,21 @@
+'use strict'; // eslint-disable-line semi
+
+const chalk = require('chalk')
+
+const nextColor = (function () {
+  const colors = ['red', 'green', 'yellow', 'cyan', 'magenta']
+  let i = 0
+  return function () {
+    return colors[i++ % colors.length]
+  }
+}())
+
+const CHARS = 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789'
+const LEN = 4
+
+module.exports = function makeId () {
+  const color = nextColor()
+  let id = '', i = LEN
+  while (i--) id += CHARS.substr(Math.random() * CHARS.length, 1)
+  return chalk.dim[color](id)
+}

lib/volleyball.js

@@ -0,0 +1,97 @@
+'use strict'; // eslint-disable-line semi
+
+const http = require('http')
+const debug = require('debug')
+const chalk = require('chalk')
+const filesize = require('filesize')
+const makeId = require('./id')
+
+const sp = ' '
+
+module.exports = new Volleyball()
+
+function Volleyball (config = {}) {
+  const logger = getLogger(config.debug)
+
+  function volleyball (req, res, next) {
+    const shared = {
+      logger: logger,
+      id: makeId(),
+      time: process.hrtime()
+    }
+
+    logReq(req, shared)
+
+    res.on('finish', () => logRes(res, shared))
+    res.on('close', () => logClose(res, shared))
+
+    next()
+  }
+  volleyball.custom = volleyballFactory
+
+  return volleyball
+}
+
+function volleyballFactory (...args) {
+  return new Volleyball(...args)
+}
+
+function getLogger (debugChoice) {
+  if (!debugChoice) return defaultLogger
+  if (debugChoice === true) return debug('http')
+  if (typeof debugChoice === 'string') return debug(debugChoice)
+  if (typeof debugChoice === 'function') return debugChoice
+}
+
+function defaultLogger (str) {
+  process.stdout.write(str + '\n')
+}
+
+function logReq (req, shared) {
+  const bytes = +req.headers['content-length']
+  const type = req.headers['content-type']
+
+  let reqLine = chalk.dim('<-') + ` ${shared.id}    `
+  reqLine += `${chalk.bold.underline(req.method)} ${req.url} `
+  if (bytes) reqLine += chalk.blue(filesize(bytes)) + sp
+  if (type) reqLine += chalk.blue.dim(type)
+
+  shared.logger(reqLine)
+}
+
+function logRes (res, shared) {
+  const status = res.statusCode
+  const meaning = http.STATUS_CODES[status]
+  const bytes = +res.getHeader('content-length')
+  const type = res.getHeader('content-type')
+
+  let statusColor
+  if (status >= 500) statusColor = 'red'
+  else if (status >= 400) statusColor = 'yellow'
+  else if (status >= 300) statusColor = 'cyan'
+  else if (status >= 200) statusColor = 'green'
+  else statusColor = 'reset'
+
+  let resLine = `   ${shared.id} ` + chalk.dim('->') + sp
+  resLine += chalk[statusColor](`${status} ${meaning}`) + sp
+  if (bytes) resLine += chalk.blue(filesize(bytes)) + sp
+  if (type) resLine += chalk.blue.dim(type) + sp
+  resLine += chalk.dim(`(<-> ${msDiff(shared.time)} ms)`)
+
+  shared.logger(resLine)
+}
+
+function logClose (res, shared) {
+  let closeLine = `${chalk.dim('><')} ${shared.id} ${chalk.dim('><')} `
+  closeLine += chalk.red('connection closed before res end/flush')
+
+  shared.logger(closeLine)
+}
+
+function msDiff (time) {
+  var diff = process.hrtime(time)
+  const seconds = diff[0]
+  const nanoseconds = diff[1]
+  const ms = (seconds * 1e9 + nanoseconds) / 1e6
+  return ms.toFixed(1)
+}

package.json

@@ -0,0 +1,41 @@
+{
+  "name": "volleyball",
+  "version": "1.0.0",
+  "description": "🏐 Tiny HTTP logger for Express showing asynchronous requests and responses",
+  "homepage": "https://github.com/glebec/volleyball",
+  "main": "lib/volleyball.js",
+  "scripts": {
+    "test": "DEBUG=http,custom mocha",
+    "lint": "eslint **/*.js --ignore-pattern node_modules"
+  },
+  "author": "Gabriel Lebec <[email protected]> (https://github.com/glebec)",
+  "license": "MIT",
+  "devDependencies": {
+    "chai": "^3.5.0",
+    "eslint": "^3.3.0",
+    "eslint-config-fullstack": "^1.4.1",
+    "express": "^4.14.0",
+    "mocha": "^3.0.2",
+    "supertest": "^2.0.0"
+  },
+  "dependencies": {
+    "chalk": "^1.1.3",
+    "debug": "^2.2.0",
+    "filesize": "^3.3.0"
+  },
+  "repository": {
+    "type": "git",
+    "url": "https://github.com/glebec/volleyball.git"
+  },
+  "bugs": "https://github.com/glebec/volleyball/issues",
+  "keywords": [
+    "HTTP",
+    "logging",
+    "logger",
+    "log",
+    "middleware",
+    "async",
+    "req",
+    "res"
+  ]
+}

test/test.js

@@ -0,0 +1,77 @@
+'use strict'; // eslint-disable-line semi
+const supertest = require('supertest')
+const expect = require('chai').expect
+const express = require('express')
+const chalk = require('chalk')
+const debug = require('debug')
+debug.log = console.log.bind(console)
+const volleyball = require('../lib/volleyball')
+
+describe('volleyball', function () {
+
+  it('is middleware', function () {
+    expect(volleyball).to.be.a('function')
+    expect(volleyball).to.have.length(3)
+  })
+
+})
+
+describe('An Express app', function () {
+
+  const originalWrite = process.stdout.write
+  let app, client, record
+  beforeEach(function () {
+    record = ''
+    process.stdout.write = function (str) {
+      record += chalk.stripColor(str)
+      originalWrite.call(process.stdout, str)
+    }
+    app = express()
+    client = supertest(app)
+  })
+
+  afterEach(function () {
+    process.stdout.write = originalWrite
+  })
+
+  function test (done) {
+    client.get('/')
+    .expect(404)
+    .end(function (err) {
+      if (err) return done(err)
+      expect(record).to.match(/GET \/[\s\S]+404 Not Found/gm)
+      done()
+    })
+  }
+
+  describe('using volleyball', function () {
+
+    beforeEach(function () {
+      app.use(volleyball)
+    })
+
+    it('logs requests and responses', test)
+
+  })
+
+  describe('using volleyball with debug true', function () {
+
+    beforeEach(function () {
+      app.use(volleyball.custom({debug: true}))
+    })
+
+    it('logs requests and responses', test)
+
+  })
+
+  describe('using volleyball with debug custom', function () {
+
+    beforeEach(function () {
+      app.use(volleyball.custom({debug: 'custom'}))
+    })
+
+    it('logs requests and responses', test)
+
+  })
+
+})