From 54e420eb58a8bb78310ae8eac63252616975c9b9 Mon Sep 17 00:00:00 2001
From: osher <osher.filter@gmail.com>
Date: Tue, 31 Jul 2012 14:32:03 +0300
Subject: [PATCH 1/2] Update lib/layouts.js
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Errors sometimes carry additional attributes on them as part of the passed error data.
A utility that utilizes it, for example - is called 'errs', which is in use for instance 'nano' - the couch-db driver.

when only the stack is printed - all the additional information that is augmented on the error object does not sink to the log and is lost.

consider the following code:

```
//the oups throwing utility
function oups(){
  e = new Error();
  extend(
    { message    : "Oups error"
    , description: "huston, we got a problem"
    , status     : "MESS"
    , errorCode  : 991
    , arr :[1,2,3,4,{}]
    , data: 
      { c:{}
      , d:{e:{}}
      }
    }
  throw e;
}

var log = require('log4js')

try{
  oups()
} catch( e ) {
   log.error("error on oups", e );
}

```


output before the fix

```
error on oups Error: Oups error
    at repl:1:11
    at REPLServer.eval (repl.js:80:21)
    at Interface.<anonymous> (repl.js:182:12)
    at Interface.emit (events.js:67:17)
    at Interface._onLine (readline.js:162:10)
    at Interface._line (readline.js:426:8)
    at Interface._ttyWrite (readline.js:603:14)
    at ReadStream.<anonymous> (readline.js:82:12)
    at ReadStream.emit (events.js:88:20)
```


output after the fix would be

```
error on oups { [Error: My error message]
  name: 'Error',
  description: 'huston, we got a problem',
  status: 'MESS',
  errorCode: 991,
  arr: [ 1, 2, 3, 4, {} ],
  data: { c: {}, d: { e: {} } } }
Error: Oups error
    at repl:1:11
    at REPLServer.eval (repl.js:80:21)
    at Interface.<anonymous> (repl.js:182:12)
    at Interface.emit (events.js:67:17)
    at Interface._onLine (readline.js:162:10)
    at Interface._line (readline.js:426:8)
    at Interface._ttyWrite (readline.js:603:14)
    at ReadStream.<anonymous> (readline.js:82:12)
    at ReadStream.emit (events.js:88:20)
```
---
 lib/layouts.js | 5 ++---
 1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/lib/layouts.js b/lib/layouts.js
index 7daec65..1b233ea 100644
--- a/lib/layouts.js
+++ b/lib/layouts.js
@@ -49,10 +49,9 @@ function formatLogData(logData) {
         if (output) {
             output += ' ';
         }
+        output += util.inspect(item);
         if (item && item.stack) {
-            output += item.stack;
-        } else {
-            output += util.inspect(item);
+            output += "\n" + item.stack;
         }
     });
 

From f948b5f5cdd3f4efb58d02cdc7b2bd191256bc4f Mon Sep 17 00:00:00 2001
From: osher <osher.filter@gmail.com>
Date: Wed, 1 Aug 2012 10:11:37 +0300
Subject: [PATCH 2/2] Add unit tests - layouts-test.js

---
 test/layouts-test.js | 49 +++++++++++++++++++++++++++++++++++++++++---
 1 file changed, 46 insertions(+), 3 deletions(-)

diff --git a/test/layouts-test.js b/test/layouts-test.js
index 5930276..660b8c9 100644
--- a/test/layouts-test.js
+++ b/test/layouts-test.js
@@ -76,8 +76,50 @@ vows.describe('log4js layouts').addBatch({
                 , toString: function() { return "ERROR"; }
               }
             }), "{ thing: 1 }");
+        },
+        'should print the stacks of a passed error objects': function(layout) { 
+            assert.isArray(layout({
+                data: [ new Error() ]
+              , startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
+              , categoryName: "cheese"
+              , level: {
+                  colour: "green"
+                , toString: function() { return "ERROR"; }
+              }
+            }).match(/Error\s+at Object\.<anonymous>\s+\((.*)test[\\\/]layouts-test\.js\:\d+\:\d+\)\s+at runTest/)
+            , 'regexp did not return a match');
+        },
+        'with passed augmented errors': 
+        { topic:
+          function(layout){ 
+              var e = new Error("My Unique Error Message");
+              e.augmented = "My Unique attribute value"
+              e.augObj = { at1: "at2" }
+              return layout({
+                  data: [ e ]
+                , startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
+                , categoryName: "cheese"
+                , level: {
+                    colour: "green"
+                  , toString: function() { return "ERROR"; }
+                }
+              });
+          },
+          'should print error the contained error message': function(layoutOutput) { 
+              var m = layoutOutput.match(/\{ \[Error: My Unique Error Message\]/);
+              assert.isArray(m);
+          },
+          'should print error augmented string attributes': function(layoutOutput) { 
+              var m = layoutOutput.match(/augmented:\s'My Unique attribute value'/);
+              assert.isArray(m);
+          },
+          'should print error augmented object attributes': function(layoutOutput) { 
+              var m = layoutOutput.match(/augObj:\s\{ at1: 'at2' \}/);
+              assert.isArray(m);
+          }
         }
 
+
     },
 
     'basicLayout': {
@@ -106,10 +148,11 @@ vows.describe('log4js layouts').addBatch({
             output = layout(event);
             lines = output.split(/\n/);
 
-            assert.equal(lines.length, stack.length);
-            assert.equal(lines[0], "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test Error: Some made-up error");
+            assert.equal(lines.length - 1, stack.length);
+            assert.equal(lines[0], "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test [Error: Some made-up error]");
+
             for (var i = 1; i < stack.length; i++) {
-                assert.equal(lines[i+1], stack[i+1]);
+                assert.equal(lines[i+2], stack[i+1]);
             }
         },
         'should output any extra data in the log event as util.inspect strings': function(args) {