diff --git a/src/Azure.Functions.Cli/Actions/HostActions/StartHostAction.cs b/src/Azure.Functions.Cli/Actions/HostActions/StartHostAction.cs index 95d60cb1e..9ad5d8bf8 100644 --- a/src/Azure.Functions.Cli/Actions/HostActions/StartHostAction.cs +++ b/src/Azure.Functions.Cli/Actions/HostActions/StartHostAction.cs @@ -78,6 +78,8 @@ internal class StartHostAction : BaseAction public string? HostRuntime { get; set; } + public string UserLogLevel { get; set; } + public StartHostAction(ISecretsManager secretsManager, IProcessManager processManager) { _secretsManager = secretsManager; @@ -178,6 +180,11 @@ public override ICommandLineParserResult ParseArgs(string[] args) .WithDescription($"If provided, determines which version of the host to start. Allowed values are '{DotnetConstants.InProc6HostRuntime}', '{DotnetConstants.InProc8HostRuntime}', and 'default' (which runs the out-of-process host).") .Callback(startHostFromRuntime => HostRuntime = startHostFromRuntime); + Parser + .Setup("userLogLevel") + .WithDescription($"If provided, determines the log level of user logs. Allowed values are '{LogLevel.Trace}', '{LogLevel.Debug}', '{LogLevel.Information}', '{LogLevel.Warning}', '{LogLevel.Error}', '{LogLevel.Critical}' and '{LogLevel.None}'. The default is Information.") + .Callback(userLogLevel => UserLogLevel = userLogLevel); + var parserResult = base.ParseArgs(args); bool verboseLoggingArgExists = parserResult.UnMatchedOptions.Any(o => o.LongName.Equals("verbose", StringComparison.OrdinalIgnoreCase)); // Input args do not contain --verbose flag @@ -190,7 +197,7 @@ public override ICommandLineParserResult ParseArgs(string[] args) private async Task BuildWebHost(ScriptApplicationHostOptions hostOptions, Uri listenAddress, Uri baseAddress, X509Certificate2 certificate) { - LoggingFilterHelper loggingFilterHelper = new LoggingFilterHelper(_hostJsonConfig, VerboseLogging); + LoggingFilterHelper loggingFilterHelper = new LoggingFilterHelper(_hostJsonConfig, VerboseLogging, UserLogLevel); if (GlobalCoreToolsSettings.CurrentWorkerRuntime == WorkerRuntime.dotnet || GlobalCoreToolsSettings.CurrentWorkerRuntime == WorkerRuntime.dotnetIsolated) { @@ -400,7 +407,10 @@ public override async Task RunAsync() { await PreRunConditions(); var isVerbose = VerboseLogging.HasValue && VerboseLogging.Value; - + + //set --userLogLevel flag + ConfigureUserLogLevelFromFlagOrSettings(); + // Return if running is delegated to another version of Core Tools if (await TryHandleInProcDotNetLaunchAsync()) { @@ -831,5 +841,37 @@ private void EnsureWorkerRuntimeIsSet() // Update local.settings.json WorkerRuntimeLanguageHelper.SetWorkerRuntime(_secretsManager, GlobalCoreToolsSettings.CurrentWorkerRuntime.ToString()); } + + private void ConfigureUserLogLevelFromFlagOrSettings() + { + if (!string.IsNullOrEmpty(UserLogLevel)) + { + if (IsValidUserLogLevel(UserLogLevel)) + { + Environment.SetEnvironmentVariable("AzureFunctionsJobHost__Logging__LogLevel__Function", UserLogLevel); + } + } + else + { + UserLogLevel = GetUserLogLevelFromLocalSettings(); + } + } + + private bool IsValidUserLogLevel(string UserLogLevel) + { + if (LoggingFilterHelper.ValidUserLogLevels.Contains(UserLogLevel, StringComparer.OrdinalIgnoreCase) == false) + { + throw new CliException($"The userLogLevel value provided, '{UserLogLevel}', is invalid. Valid values are '{string.Join("', '", LoggingFilterHelper.ValidUserLogLevels)}'. The default is Information."); + } + return true; + } + + private string GetUserLogLevelFromLocalSettings() + { + var UserLogLevel = Environment.GetEnvironmentVariable(Constants.FunctionsLoggingLogLevel) + ?? _secretsManager.GetSecrets().FirstOrDefault(s => s.Key.Equals(Constants.FunctionsLoggingLogLevel, StringComparison.OrdinalIgnoreCase)).Value; + + return UserLogLevel; + } } } diff --git a/src/Azure.Functions.Cli/Common/Constants.cs b/src/Azure.Functions.Cli/Common/Constants.cs index 83f80bee3..228c81555 100644 --- a/src/Azure.Functions.Cli/Common/Constants.cs +++ b/src/Azure.Functions.Cli/Common/Constants.cs @@ -96,6 +96,7 @@ internal static class Constants public const string AzureDevSessionsRemoteHostName = "AzureDevSessionsRemoteHostName"; public const string AzureDevSessionsPortSuffixPlaceholder = ""; public const string GitHubReleaseApiUrl = "https://api.github.com/repos/Azure/azure-functions-core-tools/releases/latest"; + public const string FunctionsLoggingLogLevel = "AzureFunctionsJobHost__Logging__LogLevel__Function"; // Sample format https://n12abc3t-.asse.devtunnels.ms/ diff --git a/src/Azure.Functions.Cli/Common/Utilities.cs b/src/Azure.Functions.Cli/Common/Utilities.cs index d9670e698..9de97b321 100644 --- a/src/Azure.Functions.Cli/Common/Utilities.cs +++ b/src/Azure.Functions.Cli/Common/Utilities.cs @@ -26,6 +26,7 @@ internal static class Utilities { public const string LogLevelSection = "loglevel"; public const string LogLevelDefaultSection = "Default"; + public const string LogLevelFunctionSection = "Function"; internal static void PrintLogo() { diff --git a/src/Azure.Functions.Cli/Diagnostics/LoggingFilterHelper.cs b/src/Azure.Functions.Cli/Diagnostics/LoggingFilterHelper.cs index 057e6375c..dc3b21a28 100644 --- a/src/Azure.Functions.Cli/Diagnostics/LoggingFilterHelper.cs +++ b/src/Azure.Functions.Cli/Diagnostics/LoggingFilterHelper.cs @@ -18,8 +18,9 @@ public class LoggingFilterHelper public const string Ci_Continuous_Integration = "CONTINUOUS_INTEGRATION"; // Travis CI, Cirrus CI public const string Ci_Build_Number = "BUILD_NUMBER"; // Travis CI, Cirrus CI public const string Ci_Run_Id = "RUN_ID"; // TaskCluster, dsari + public static readonly string[] ValidUserLogLevels = ["Trace", "Debug", "Information", "Warning", "Error", "Critical", "None"]; - public LoggingFilterHelper(IConfigurationRoot hostJsonConfig, bool? verboseLogging) + public LoggingFilterHelper(IConfigurationRoot hostJsonConfig, bool? verboseLogging, string userLogLevel = null) { VerboseLogging = verboseLogging.HasValue && verboseLogging.Value; @@ -31,10 +32,22 @@ public LoggingFilterHelper(IConfigurationRoot hostJsonConfig, bool? verboseLoggi { SystemLogDefaultLogLevel = LogLevel.Information; } - if (Utilities.LogLevelExists(hostJsonConfig, Utilities.LogLevelDefaultSection, out LogLevel logLevel)) + if (Utilities.LogLevelExists(hostJsonConfig, Utilities.LogLevelDefaultSection, out LogLevel defaultLogLevel)) { - SystemLogDefaultLogLevel = logLevel; - UserLogDefaultLogLevel = logLevel; + SystemLogDefaultLogLevel = defaultLogLevel; + UserLogDefaultLogLevel = defaultLogLevel; + } + + // set user log value to Function + if ( Utilities.LogLevelExists(hostJsonConfig, Utilities.LogLevelFunctionSection, out LogLevel functionLogLevel)) + { + UserLogDefaultLogLevel = functionLogLevel; + } + + // set user log value to --userLoglevel Flag + if (!string.IsNullOrEmpty(userLogLevel) && Enum.TryParse(userLogLevel, true, out LogLevel UserLogLevel)) + { + UserLogDefaultLogLevel = UserLogLevel; } } @@ -68,5 +81,6 @@ internal bool IsCiEnvironment(bool verboseLoggingArgExists) } return false; } + } } diff --git a/test/Azure.Functions.Cli.Tests/E2E/StartTests.cs b/test/Azure.Functions.Cli.Tests/E2E/StartTests.cs index 81bb91483..f10f8d3ef 100644 --- a/test/Azure.Functions.Cli.Tests/E2E/StartTests.cs +++ b/test/Azure.Functions.Cli.Tests/E2E/StartTests.cs @@ -10,6 +10,7 @@ using Azure.Functions.Cli.Common; using Azure.Functions.Cli.Tests.E2E.Helpers; using FluentAssertions; +using Microsoft.Azure.Storage; using Xunit; using Xunit.Abstractions; @@ -1857,6 +1858,296 @@ await CliTester.Run(new RunConfiguration[] } } + [Fact] + [Trait(TestTraits.Group, TestTraits.RequiresNestedInProcArtifacts)] + public async Task Start_DotnetApp_WithUserLogLevelFlag_ShowDebugLogsInConsole() + { + var DebugLogMessage = "This is a debug log message"; + + await CliTester.Run(new RunConfiguration[] + { + new RunConfiguration + { + Commands = new[] + { + "init . --worker-runtime dotnet", + "new --template Httptrigger --name HttpTrigger" + }, + Test = async (workingDir, _, _) => + { + // Add debug logs to FunctionApp.cs + var functionAppPath = Path.Combine(workingDir, "HttpTrigger.cs"); + if (File.Exists(functionAppPath)) + { + var content = await File.ReadAllTextAsync(functionAppPath); + content = content.Replace( + "log.LogInformation(\"C# HTTP trigger function processed a request.\");", + $"log.LogInformation(\"C# HTTP trigger function processed a request.\");\nlog.LogDebug(\"{DebugLogMessage}\");" + ); + await File.WriteAllTextAsync(functionAppPath, content); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + }, + new RunConfiguration + { + Commands = new[] + { + $"start --port {_funcHostPort} --userLogLevel Debug" + }, + ExpectExit = false, + OutputContains = new[] + { + DebugLogMessage + }, + Test = async (_, p, stdout) => + { + using (var client = new HttpClient() { BaseAddress = new Uri($"http://localhost:{_funcHostPort}/") }) + { + (await WaitUntilReady(client)).Should().BeTrue(because: _serverNotReady); + var response = await client.GetAsync("/api/HttpTrigger?name=Test"); + response.StatusCode.Should().Be(HttpStatusCode.OK); + p.Kill(); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + } + }, _output); + } + + [Fact] + [Trait(TestTraits.Group, TestTraits.RequiresNestedInProcArtifacts)] + public async Task Start_DotnetApp_WithDebugLogs_DisplaysDebugLogsInConsole() + { + var DebugLogMessage = "This is a debug log message"; + + await CliTester.Run(new RunConfiguration[] + { + new RunConfiguration + { + Commands = new[] + { + "init . --worker-runtime dotnet", + "new --template Httptrigger --name HttpTrigger" + }, + Test = async (workingDir, _, _) => + { + // Add debug logs to FunctionApp.cs + var functionAppPath = Path.Combine(workingDir, "HttpTrigger.cs"); + if (File.Exists(functionAppPath)) + { + var content = await File.ReadAllTextAsync(functionAppPath); + content = content.Replace( + "log.LogInformation(\"C# HTTP trigger function processed a request.\");", + $"log.LogInformation(\"C# HTTP trigger function processed a request.\");\nlog.LogDebug(\"{DebugLogMessage}\");" + ); + await File.WriteAllTextAsync(functionAppPath, content); + } + + // Update local.settings.json + var localSettingsPath = Path.Combine(workingDir, "local.settings.json"); + if (File.Exists(localSettingsPath)) + { + var settingsContent = await File.ReadAllTextAsync(localSettingsPath); + settingsContent = settingsContent.Replace( + "\"Values\": {", + "\"Values\": {\n \"AzureFunctionsJobHost__Logging__LogLevel__Function\": \"Debug\"," + ); + await File.WriteAllTextAsync(localSettingsPath, settingsContent); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + }, + new RunConfiguration + { + Commands = new[] + { + $"start --port {_funcHostPort}" + }, + ExpectExit = false, + OutputContains = new[] + { + DebugLogMessage + }, + Test = async (_, p, stdout) => + { + using (var client = new HttpClient() { BaseAddress = new Uri($"http://localhost:{_funcHostPort}/") }) + { + (await WaitUntilReady(client)).Should().BeTrue(because: _serverNotReady); + var response = await client.GetAsync("/api/HttpTrigger?name=Test"); + response.StatusCode.Should().Be(HttpStatusCode.OK); + p.Kill(); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + } + }, _output); + } + + [Fact] + [Trait(TestTraits.Group, TestTraits.RequiresNestedInProcArtifacts)] + public async Task Start_NodeApp_DisplaysDebugLogsInConsole() + { + await CliTester.Run(new RunConfiguration[] + { + new RunConfiguration + { + Commands = new[] + { + "init . --worker-runtime node", + "new --template Httptrigger --name HttpTrigger" + }, + Test = async (workingDir, _, _) => + { + // Add debug logs to FunctionApp.cs + var functionAppPath = Path.Combine(workingDir,"src", "functions", "HttpTrigger.js"); + if (File.Exists(functionAppPath)) + { + var content = await File.ReadAllTextAsync(functionAppPath); + content = content.Replace( + $"context.log(`Http function processed request for url \"${{request.url}}\"`);", + $"context.log(`Http function processed request for url \"${{request.url}}\"`);\ncontext.debug(\"This is a debug log message\");" + ); + await File.WriteAllTextAsync(functionAppPath, content); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + }, + new RunConfiguration + { + Commands = new[] + { + $"start --port {_funcHostPort} --userLogLevel Debug" + }, + ExpectExit = false, + OutputContains = new[] + { + "This is a debug log message" + }, + Test = async (_, p, stdout) => + { + using (var client = new HttpClient() { BaseAddress = new Uri($"http://localhost:{_funcHostPort}/") }) + { + (await WaitUntilReady(client)).Should().BeTrue(because: _serverNotReady); + var response = await client.GetAsync("/api/HttpTrigger?name=Test"); + response.StatusCode.Should().Be(HttpStatusCode.OK); + p.Kill(); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + } + }, _output); + } + + [Fact] + [Trait(TestTraits.Group, TestTraits.RequiresNestedInProcArtifacts)] + public async Task Start_DotnetApp_DisplaysDebugLogsInConsole() + { + await CliTester.Run(new RunConfiguration[] + { + new RunConfiguration + { + Commands = new[] + { + "init . --worker-runtime dotnet-isolated", + "new --template Httptrigger --name HttpTrigger" + }, + Test = async (workingDir, _, _) => + { + //set minimum level in Program.cs + var functionProgramFile = Path.Combine(workingDir, "Program.cs"); + if (File.Exists(functionProgramFile)) + { + var Programcontent = await File.ReadAllTextAsync(functionProgramFile); + Programcontent = Programcontent.Replace( + $"using Microsoft.Extensions.Hosting;", + $"using Microsoft.Extensions.Hosting;\r\nusing Microsoft.Extensions.Logging;" + ). + Replace( + $"builder.Build().Run();", + $"builder.Logging.SetMinimumLevel(LogLevel.Debug);\r\nbuilder.Build().Run();" + ); + await File.WriteAllTextAsync(functionProgramFile, Programcontent); + } + + // Add debug logs to FunctionApp.cs + var functionAppPath = Path.Combine(workingDir,"HttpTrigger.cs"); + if (File.Exists(functionAppPath)) + { + var content = await File.ReadAllTextAsync(functionAppPath); + content = content.Replace( + $"_logger.LogInformation(\"C# HTTP trigger function processed a request.\");", + $"_logger.LogInformation(\"C# HTTP trigger function processed a request.\");\r\n_logger.LogDebug(\"This is Debug log from Dotnet-Isolated function app.\");" + ); + await File.WriteAllTextAsync(functionAppPath, content); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + }, + new RunConfiguration + { + Commands = new[] + { + $"start --port {_funcHostPort} --userLogLevel Debug" + }, + ExpectExit = false, + OutputContains = new[] + { + "This is Debug log from Dotnet-Isolated function app." + }, + Test = async (_, p, stdout) => + { + using (var client = new HttpClient() { BaseAddress = new Uri($"http://localhost:{_funcHostPort}/") }) + { + (await WaitUntilReady(client)).Should().BeTrue(because: _serverNotReady); + var response = await client.GetAsync("/api/HttpTrigger?name=Test"); + response.StatusCode.Should().Be(HttpStatusCode.OK); + p.Kill(); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + } + }, _output); + } + + [Theory] + [InlineData("dotnet", "TestDotnet")] + [InlineData("dotnet-isolated", "TestDotnetIsolated")] + [InlineData("node", "TestNode")] + public async Task Start_FunctionApp_ExpectedToFail_WithInvalidUserLogLevel(string WorkerRuntime, string UserLogLevel) + { + await CliTester.Run(new RunConfiguration[] + { + new RunConfiguration + { + Commands = new[] + { + $"init . --worker-runtime {WorkerRuntime}", + $"new --template Httptrigger --name HttpTrigger", + }, + CommandTimeout = TimeSpan.FromSeconds(300) + }, + new RunConfiguration + { + Commands = new[] + { + $"start --port {_funcHostPort} --userLogLevel {UserLogLevel}" + }, + ExpectExit = true, + ExitInError = true, + ErrorContains = [$"The userLogLevel value provided, '{UserLogLevel}', is invalid. Valid values are '{string.Join("', '", LoggingFilterHelper.ValidUserLogLevels)}'. The default is Information."], + Test = async (workingDir, p, _) => + { + using (var client = new HttpClient() { BaseAddress = new Uri($"http://localhost:{_funcHostPort}") }) + { + await Task.Delay(TimeSpan.FromSeconds(2)); + } + }, + CommandTimeout = TimeSpan.FromSeconds(300) + } + }, _output); + } + private async Task WaitUntilReady(HttpClient client) { for (var limit = 0; limit < 10; limit++)