Logging

README.md

@@ -170,6 +170,23 @@ The `id` parameter is only required for 'create.js'.  This will be
 the ID CloudFormation will use to track the resource.  If `id` is
 provided then `data` must also be defined.
 
+### Logging
+
+Logging is pre-configured via the [winston][winston-github-url] library and can be included
+via lambda-formation:
+
+    var logger = require('lambda-formation').logger;
+
+Within your code use the winston shortcut methods `log`, `info`, `debug`:
+
+    logger.log('info', 'My messages');
+    logger.info('My message');
+    logger.debug('My message');
+    ...
+
+Framework internal logs will be logged with log-level `debug`.
+To enable them to be logged to CloudWatch set the environment variable `CFN_LOG_LEVEL` to `debug`.
+
 ## Examples
 
 * [lambda-formation-example-resources](https://github.com/SungardAS/lambda-formation-example-resources)
@@ -209,3 +226,5 @@ https://coveralls.io/r/SungardAS/lambda-formation
 [aws-custom-resources-url]: http://docs.aws.amazon.com/AWSCloudFormation/latest/UserGuide/template-custom-resources.html
 [lambda-formation-image]: ./docs/images/lambda-formation.png?raw=true
 [lambda-formation-url]: https://github.com/SungardAS/lambda-formation
+
+[winston-github-url]: https://github.com/winstonjs/winston

index.js

@@ -1,7 +1,9 @@
 var util = require('./lib/util');
 var resource = require('./lib/resource');
 var project = require('./lib/project');
+var logger = require('./lib/logger');
 
 module.exports.util = util;
 module.exports.resource = resource;
 module.exports.project = project;
+module.exports.logger = logger;

lib/logger/index.js

@@ -0,0 +1,12 @@
+var winston = require("winston");
+
+module.exports = new (winston.Logger)({
+    level: process.env.CFN_LOG_LEVEL || 'info',
+    transports: [
+        new (winston.transports.Console)({
+            json: true,
+            stringify: true,
+            timestamp: true
+        })
+    ]
+});

lib/project/handler.js

@@ -4,6 +4,7 @@ var callerId = require("caller-id");
 var fs = require("fs");
 var path = require("path");
 var util = require("../util");
+var logger = require("../logger");
 
 
 /**
@@ -17,6 +18,8 @@ var util = require("../util");
 module.exports = function handler(event,context) {
   var ev;
 
+  logger.debug('Lambda-formation project entrypoint', { event: event, context: context });
+
   try {
     ev = util.normalizeEvent(event,context);
   }

lib/resource/handler.js

@@ -2,6 +2,7 @@ var _ = require("lodash");
 var callerId = require("caller-id");
 var path = require("path");
 var util = require("../util");
+var logger = require("../logger");
 
 /**
  * Entrypoint for a ResourceType
@@ -14,6 +15,8 @@ module.exports = function(event, context) {
 
   var ev;
 
+  logger.debug('Lambda-formation resource entrypoint', { event: event, context: context });
+
   try {
     if (event._normalized !== true) {
       ev = util.normalizeEvent(event,context);

package.json

@@ -27,13 +27,15 @@
     "cfn-responder": "^1.0.2",
     "lodash": "^4.17.4",
     "request": "^2.81.0",
-    "underscore.string": "^3.3.4"
+    "underscore.string": "^3.3.4",
+    "winston": "^2.3.1"
   },
   "devDependencies": {
     "assert": "^1.4.1",
     "coveralls": "^2.13.1",
     "istanbul": "^0.4.5",
     "mocha": "^3.4.1",
-    "nock": "^9.0.13"
+    "nock": "^9.0.13",
+    "vows": "^0.8.1"
   }
 }

test/unit/logger.test.js

@@ -0,0 +1,27 @@
+var lf = require('../../');
+var winston = require('winston');
+var vows = require('vows'),
+    assert = require('assert');
+
+describe("logger", function () {
+    before(function() {
+        lf.logger.clear();
+        lf.logger.add(winston.transports.Memory);
+    });
+
+    it("should exist in lambda-formation", function () {
+        assert.isObject(lf.logger);
+        assert.isFunction(lf.logger.log);
+    });
+
+    it("should log only info messages by default", function () {
+        lf.logger.log('debug', 'foobar1');
+        lf.logger.log('debug', 'foobar2');
+
+        lf.logger.log('info', 'foobar1');
+        lf.logger.log('info', 'foobar2');
+
+        assert.include(lf.logger.transports['memory'].writeOutput, 'info: foobar1');
+        assert.notInclude(lf.logger.transports['memory'].writeOutput, 'debug: foobar1');
+    });
+});