diff --git a/src/WebJobs.Script/Content/Script/functions.js b/src/WebJobs.Script/Content/Script/functions.js index dd8ee21591..2a2360ad27 100644 --- a/src/WebJobs.Script/Content/Script/functions.js +++ b/src/WebJobs.Script/Content/Script/functions.js @@ -33,11 +33,21 @@ function createFunction(f) { f = getEntryPoint(f, context); + // configure loggers var origLog = context.log; - context.log = function () { - value = util.format.apply(null, arguments); - origLog(value); - }; + var logLevel = function (traceLevel) { + return function () { + var message = util.format.apply(null, arguments); + origLog({ lvl: traceLevel, msg: message }); + }; + } + // set default log to 'info' + var log = logLevel(3); + ['error', 'warn', 'info', 'verbose'].forEach((level, index) => { + var traceLevel = index + 1; + log[level] = logLevel(traceLevel); + }); + context.log = log; context.done = function (err, result) { if (context._done) { @@ -117,4 +127,3 @@ function getEntryPoint(f, context) { return f; } - diff --git a/src/WebJobs.Script/Description/Node/NodeFunctionInvoker.cs b/src/WebJobs.Script/Description/Node/NodeFunctionInvoker.cs index 786b2eee33..8a5f556402 100644 --- a/src/WebJobs.Script/Description/Node/NodeFunctionInvoker.cs +++ b/src/WebJobs.Script/Description/Node/NodeFunctionInvoker.cs @@ -4,6 +4,7 @@ using System; using System.Collections.Generic; using System.Collections.ObjectModel; +using System.Diagnostics; using System.Dynamic; using System.Globalization; using System.IO; @@ -271,12 +272,15 @@ private Dictionary CreateScriptExecutionContext(object input, Da // create a TraceWriter wrapper that can be exposed to Node.js var log = (Func>)(p => { - string text = p as string; - if (text != null) + var logData = (IDictionary)p; + string message = (string)logData["msg"]; + if (message != null) { try { - traceWriter.Info(text); + TraceLevel level = (TraceLevel)logData["lvl"]; + var evt = new TraceEvent(level, message); + traceWriter.Trace(evt); } catch (ObjectDisposedException) { diff --git a/test/WebJobs.Script.Tests.Integration/NodeEndToEndTests.cs b/test/WebJobs.Script.Tests.Integration/NodeEndToEndTests.cs index e5e5195be4..71c2a918f8 100644 --- a/test/WebJobs.Script.Tests.Integration/NodeEndToEndTests.cs +++ b/test/WebJobs.Script.Tests.Integration/NodeEndToEndTests.cs @@ -246,6 +246,19 @@ public async Task Scenario_Logging() Assert.Equal("This is a test", logEntry["message"]); Assert.Equal("v6.5.0", (string)logEntry["version"]); Assert.Equal(testData, logEntry["input"]); + + // verify log levels + TraceEvent[] traces = Fixture.TraceWriter.Traces.Where(t => t.Message.Contains("loglevel")).ToArray(); + Assert.Equal(TraceLevel.Info, traces[0].Level); + Assert.Equal("loglevel default", traces[0].Message); + Assert.Equal(TraceLevel.Info, traces[1].Level); + Assert.Equal("loglevel info", traces[1].Message); + Assert.Equal(TraceLevel.Verbose, traces[2].Level); + Assert.Equal("loglevel verbose", traces[2].Message); + Assert.Equal(TraceLevel.Warning, traces[3].Level); + Assert.Equal("loglevel warn", traces[3].Message); + Assert.Equal(TraceLevel.Error, traces[4].Level); + Assert.Equal("loglevel error", traces[4].Message); } [Fact] diff --git a/test/WebJobs.Script.Tests.Integration/TestScripts/Node/Scenarios/index.js b/test/WebJobs.Script.Tests.Integration/TestScripts/Node/Scenarios/index.js index 33ccb66af8..e3fd8d0976 100644 --- a/test/WebJobs.Script.Tests.Integration/TestScripts/Node/Scenarios/index.js +++ b/test/WebJobs.Script.Tests.Integration/TestScripts/Node/Scenarios/index.js @@ -39,6 +39,12 @@ var assert = require('assert'); context.log(1234); context.log(true); + context.log('loglevel default'); + context.log.info('loglevel info'); + context.log.verbose('loglevel verbose'); + context.log.warn('loglevel warn'); + context.log.error('loglevel error'); + context.done(); } else if (scenario == 'bindingData') { diff --git a/test/WebJobs.Script.Tests.Integration/TestScripts/Node/functions.tests.js b/test/WebJobs.Script.Tests.Integration/TestScripts/Node/functions.tests.js index 57af99b3a7..a1e723c233 100644 --- a/test/WebJobs.Script.Tests.Integration/TestScripts/Node/functions.tests.js +++ b/test/WebJobs.Script.Tests.Integration/TestScripts/Node/functions.tests.js @@ -230,7 +230,7 @@ describe('functions', () => { var func = functions.createFunction((context) => { context.done(); context.done(); - expect(logs[0]).to.match(/Error: 'done' has already been called.*/); + expect(logs[0].msg).to.match(/Error: 'done' has already been called.*/); }); func(context, () => {}); @@ -244,12 +244,34 @@ describe('functions', () => { func(context, () => { setImmediate(() => { - expect(logs[0]).to.match(/Error: Choose either to return a promise or call 'done'.*/); + expect(logs[0].msg).to.match(/Error: Choose either to return a promise or call 'done'.*/); done(); }); }); }); + it('logs to respective level', (done) => { + var func = functions.createFunction((context) => { + context.log('default'); + context.log.error('error'); + context.log.warn('warn'); + context.log.info('info'); + context.log.verbose('verbose'); + context.done(); + }); + + func(context, () => { + expect(logs).to.eql([ + { lvl: 3, msg: 'default' }, + { lvl: 1, msg: 'error' }, + { lvl: 2, msg: 'warn' }, + { lvl: 3, msg: 'info' }, + { lvl: 4, msg: 'verbose' }, + ]) + done(); + }); + }); + it('done passes data to binder', () => { var func = functions.createFunction((context) => { context.bindings = { result: 'res' };