remove arguments usage

Normally node-bunyan automatically adds this field if it's omitted,
but it uses lodash to generate the timestamp, which in turn uses
a costly regex to figure out if the date method is available in an
env. That particular call was consuming a lot of cpu ticks, sitting
up top on the profiler log.

lib/RequestLogger.js

@@ -6,6 +6,7 @@ const LogLevel = require('./LogLevel.js');
 const Utils = require('./Utils.js');
 const serializeUids = Utils.serializeUids;
 const generateUid = Utils.generateUid;
+const objectCopy = Utils.objectCopy;
 
 function ensureUidValidity(uid) {
     if (uid.indexOf(':') !== -1) {
@@ -26,7 +27,7 @@ class EndLogger {
                            + ' once.');
         // We can alter current instance, as it won't be usable after this
         // call.
-        this.fields = Object.assign(this.fields, data || {});
+        this.fields = objectCopy(this.fields, data || {});
         return this.logger.log(level, msg, this.fields, true);
     }
 
@@ -45,7 +46,7 @@ class EndLogger {
      */
     addDefaultFields(fields) {
         const oldFields = this.fields;
-        this.fields = Object.assign({}, this.fields, fields);
+        this.fields = objectCopy({}, this.fields, fields);
         return oldFields;
     }
 
@@ -248,7 +249,7 @@ class RequestLogger {
      */
     addDefaultFields(fields) {
         const oldFields = this.fields;
-        this.fields = Object.assign({}, this.fields, fields);
+        this.fields = objectCopy({}, this.fields, fields);
         return oldFields;
     }
 
@@ -433,17 +434,16 @@ class RequestLogger {
                 });
             return;
         }
-        const fields = Object.assign({}, logFields || {});
+        const fields = objectCopy({}, logFields || {});
         const endFlag = isEnd || false;
-        const hr = process.hrtime();
-
         /*
-         * Here, Stringify hrtime for it to stay within a one-liner when piping
-         * the output through bunyan's cli tool.
-         * Then prepend the fields to the argument Array we're preparing for
-         * bunyan
-         */
-        fields.hrtime = JSON.stringify(hr);
+        * Even though this is added automatically by bunyan, it uses an
+        * expensive regex to figure out the native Date function. By adding
+        * timestamp here avoids that expensive call.
+        */
+        if (fields.time === undefined) {
+            fields.time = new Date();
+        }
         fields.req_id = serializeUids(this.uids);
         if (endFlag) {
             this.elapsedTime = process.hrtime(this.startTime);
@@ -483,7 +483,7 @@ class RequestLogger {
      * @returns {undefined}
      */
     doLogIO(logEntry) {
-        const fields = Object.assign({}, this.fields, logEntry.fields);
+        const fields = objectCopy({}, this.fields, logEntry.fields);
 
         switch (logEntry.level) {
         case 'trace':

lib/Utils.js

@@ -40,8 +40,34 @@ function unserializeUids(stringdata) {
     return stringdata.split(':');
 }
 
+/**
+* This function copies the properties from the source object to the target object
+* @param {...object} target - object to be copied to
+* @returns {object} - target object
+*/
+function objectCopy(target, source1, source2) {
+    const result = target;
+    if (source1) {
+        Object.keys(source1).forEach( f => result[f] = source1[f]);
+    }
+
+    if (source2) {
+        Object.keys(source2).forEach( f => result[f] = source2[f]);
+    }
+    // let source;
+    // function copy(f) {
+    //     result[f] = source[f];
+    // }
+    // for (let i = 1; i < arguments.length; i++) {
+    //     source = arguments[i];
+    //     Object.keys(source).forEach(copy);
+    // }
+    return result;
+}
+
 module.exports = {
     generateUid,
     serializeUids,
     unserializeUids,
+    objectCopy,
 };

tests/unit/Utils.js

@@ -5,6 +5,7 @@ const Utils = require('../../lib/Utils.js');
 const generateUid = Utils.generateUid;
 const serializeUids = Utils.serializeUids;
 const unserializeUids = Utils.unserializeUids;
+const objectCopy = Utils.objectCopy;
 
 describe('Utils: generateUid', () => {
     it('generates a string-typed ID', (done) => {
@@ -42,3 +43,25 @@ describe('Utils: serializeUids', () => {
         done();
     });
 });
+
+describe('Utils: objectCopy', () => {
+    it('copies all the properties from source to target object', (done) => {
+        const target = { foo: 'bar' };
+        const source = { id: 1, name: 'demo', value: { a: 1, b: 2, c: 3 } };
+        const result = { foo: 'bar', id: 1, name: 'demo', value: { a: 1, b: 2, c: 3 } };
+        objectCopy(target, source);
+        assert.deepStrictEqual(target, result, 'target should have the same properties as source');
+        done();
+    });
+
+    it('copies all the properties from multiple sources to target object', (done) => {
+        const target = { foo: 'bar' };
+        const source1 = { id: 1, name: 'demo1', value: { a: 1, b: 2, c: 3 } };
+        const source2 = { req_id: 2, method: 'test', err: { code: 'error', msg: 'test' } };
+        const result = { foo: 'bar', id: 1, name: 'demo1', value: { a: 1, b: 2, c: 3 },
+            req_id: 2, method: 'test', err: { code: 'error', msg: 'test' }};
+        objectCopy(target, source1, source2);
+        assert.deepStrictEqual(target, result, 'target should have the same properties as source');
+        done();
+    });
+});