Categorized logs into system logs and user logs.

Author: yojagad

src/WebJobs.Script/Extensions/InboundEventExtensions.cs

@@ -0,0 +1,22 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using Microsoft.Azure.WebJobs.Script.Eventing.Rpc;
+using static Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types;
+using MessageType = Microsoft.Azure.WebJobs.Script.Grpc.Messages.StreamingMessage.ContentOneofCase;
+
+namespace Microsoft.Azure.WebJobs.Script
+{
+    public static class InboundEventExtensions
+    {
+        public static bool IsMessageOfType(this InboundEvent inboundEvent, MessageType typeToCheck)
+        {
+            return inboundEvent.MessageType.Equals(typeToCheck);
+        }
+
+        public static bool IsLogOfCategory(this InboundEvent inboundEvent, RpcLogCategory categoryToCheck)
+        {
+            return inboundEvent.Message.RpcLog.LogCategory.Equals(categoryToCheck);
+        }
+    }
+}

src/WebJobs.Script/Rpc/LanguageWorkerChannel.cs

@@ -20,7 +20,7 @@
 using Microsoft.Azure.WebJobs.Script.ManagedDependencies;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
-
+using static Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types;
 using FunctionMetadata = Microsoft.Azure.WebJobs.Script.Description.FunctionMetadata;
 using MsgType = Microsoft.Azure.WebJobs.Script.Grpc.Messages.StreamingMessage.ContentOneofCase;
 
@@ -81,9 +81,13 @@ internal LanguageWorkerChannel(
                 .Where(msg => msg.WorkerId == _workerId);
 
             _eventSubscriptions.Add(_inboundWorkerEvents
-                .Where(msg => msg.MessageType == MsgType.RpcLog)
+                .Where(msg => msg.IsMessageOfType(MsgType.RpcLog) && !msg.IsLogOfCategory(RpcLogCategory.System))
                 .Subscribe(Log));
 
+            _eventSubscriptions.Add(_inboundWorkerEvents
+                .Where(msg => msg.IsMessageOfType(MsgType.RpcLog) && msg.IsLogOfCategory(RpcLogCategory.System))
+                .Subscribe(SystemLog));
+
             _eventSubscriptions.Add(_eventManager.OfType<FileEvent>()
                 .Where(msg => _workerConfig.Extensions.Contains(Path.GetExtension(msg.FileChangeArguments.FullPath)))
                 .Throttle(TimeSpan.FromMilliseconds(300)) // debounce
@@ -362,6 +366,40 @@ internal void Log(RpcEvent msg)
             }
         }
 
+        internal void SystemLog(RpcEvent msg)
+        {
+            RpcLog systemLog = msg.Message.RpcLog;
+            LogLevel logLevel = (LogLevel)systemLog.Level;
+            switch (logLevel)
+            {
+                case LogLevel.Warning:
+                    _workerChannelLogger.LogWarning(systemLog.Message);
+                    break;
+
+                case LogLevel.Information:
+                    _workerChannelLogger.LogInformation(systemLog.Message);
+                    break;
+
+                case LogLevel.Error:
+                    {
+                        if (systemLog.Exception != null)
+                        {
+                            RpcException exception = new RpcException(systemLog.Message, systemLog.Exception.Message, systemLog.Exception.StackTrace);
+                            _workerChannelLogger.LogError(exception, systemLog.Message);
+                        }
+                        else
+                        {
+                            _workerChannelLogger.LogError(systemLog.Message);
+                        }
+                    }
+                    break;
+
+                default:
+                    _workerChannelLogger.LogInformation(systemLog.Message);
+                    break;
+            }
+        }
+
         internal void HandleWorkerStartStreamError(Exception exc)
         {
             _workerChannelLogger.LogError(exc, "Starting worker process failed");

test/WebJobs.Script.Tests/Extensions/InboundEventExtensionsTests.cs

@@ -0,0 +1,29 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using Microsoft.Azure.WebJobs.Script.Eventing.Rpc;
+using Xunit;
+using static Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types;
+
+namespace Microsoft.Azure.WebJobs.Script.Tests
+{
+    public class InboundEventExtensionsTests
+    {
+        [Theory]
+        [InlineData(RpcLogCategory.System)]
+        [InlineData(RpcLogCategory.User)]
+        public void TestLogCategories(RpcLogCategory categoryToTest)
+        {
+            InboundEvent inboundEvent = new InboundEvent(Guid.NewGuid().ToString(), new Grpc.Messages.StreamingMessage
+            {
+                RpcLog = new Grpc.Messages.RpcLog
+                {
+                    LogCategory = categoryToTest,
+                }
+            });
+
+            Assert.True(inboundEvent.IsLogOfCategory(categoryToTest));
+        }
+    }
+}

test/WebJobs.Script.Tests/Rpc/LanguageWorkerChannelTests.cs

@@ -21,6 +21,7 @@ namespace Microsoft.Azure.WebJobs.Script.Tests.Rpc
     public class LanguageWorkerChannelTests
     {
         private static string _expectedLogMsg = "Outbound event subscribe event handler invoked";
+        private static string _expectedSystemLogMessage = "Random system log message";
 
         private Mock<ILanguageWorkerProcess> _mockLanguageWorkerProcess = new Mock<ILanguageWorkerProcess>();
         private string _workerId = "testWorkerId";
@@ -108,6 +109,18 @@ public void SendWorkerInitRequest_PublishesOutboundEvent()
             Assert.True(traces.Any(m => string.Equals(m.FormattedMessage, _expectedLogMsg)));
         }
 
+        [Theory]
+        [InlineData(RpcLog.Types.Level.Information, RpcLog.Types.Level.Information)]
+        [InlineData(RpcLog.Types.Level.Error, RpcLog.Types.Level.Error)]
+        [InlineData(RpcLog.Types.Level.Warning, RpcLog.Types.Level.Warning)]
+        [InlineData(RpcLog.Types.Level.Trace, RpcLog.Types.Level.Information)]
+        public void SendSystemLogMessage_PublishesSystemLogMessage(RpcLog.Types.Level levelToTest, RpcLog.Types.Level expectedLogLevel)
+        {
+            _testFunctionRpcService.PublishSystemLogEvent(levelToTest);
+            var traces = _logger.GetLogMessages();
+            Assert.True(traces.Any(m => string.Equals(m.FormattedMessage, _expectedSystemLogMessage) && m.Level.ToString().Equals(expectedLogLevel.ToString())));
+        }
+
         [Fact]
         public void SendInvocationRequest_PublishesOutboundEvent()
         {

test/WebJobs.Script.Tests/Rpc/TestFunctionRpcService.cs

@@ -76,6 +76,22 @@ public void PublishWorkerInitResponseEvent()
             _eventManager.Publish(new InboundEvent(_workerId, responseMessage));
         }
 
+        public void PublishSystemLogEvent(RpcLog.Types.Level inputLevel)
+        {
+            RpcLog rpcLog = new RpcLog()
+            {
+                LogCategory = RpcLog.Types.RpcLogCategory.System,
+                Level = inputLevel,
+                Message = "Random system log message",
+            };
+
+            StreamingMessage logMessage = new StreamingMessage()
+            {
+                RpcLog = rpcLog
+            };
+            _eventManager.Publish(new InboundEvent(_workerId, logMessage));
+        }
+
         public static FunctionEnvironmentReloadResponse GetTestFunctionEnvReloadResponse()
         {
             StatusResult statusResult = new StatusResult()