Skip to content

Commit 35cf323

Browse files
committed
Add logging for Linux AppService Containers
When running on appservice containers, use the mounted log folder to write logs. To avoid using up too much space on the worker, support rolling of log files.
1 parent 041fc38 commit 35cf323

15 files changed

+794
-74
lines changed

src/WebJobs.Script.WebHost/Configuration/WebScriptHostConfigurationSource.cs

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,8 @@ public class WebScriptHostConfigurationSource : IConfigurationSource
1616

1717
public bool IsLinuxContainerEnvironment { get; set; }
1818

19+
public bool IsLinuxAppServiceEnvironment { get; set; }
20+
1921
public IConfigurationProvider Build(IConfigurationBuilder builder)
2022
{
2123
return new WebScriptHostConfigurationProvider(this);
@@ -46,7 +48,16 @@ public override void Load()
4648
// Running in App Service
4749
string home = GetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteHomePath);
4850
Data[WebHostScriptPathProperty] = Path.Combine(home, "site", "wwwroot");
49-
Data[LogPathProperty] = Path.Combine(home, "LogFiles", "Application", "Functions");
51+
52+
if (_configurationSource.IsLinuxAppServiceEnvironment)
53+
{
54+
Data[LogPathProperty] = GetEnvironmentVariable(EnvironmentSettingNames.FunctionsLogsMountPath);
55+
}
56+
else
57+
{
58+
Data[LogPathProperty] = Path.Combine(home, "LogFiles", "Application", "Functions");
59+
}
60+
5061
Data[SecretsPathProperty] = Path.Combine(home, "data", "Functions", "secrets");
5162
Data[TestDataPathProperty] = Path.Combine(home, "data", "Functions", "sampledata");
5263
}
Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,66 @@
1+
// Copyright (c) .NET Foundation. All rights reserved.
2+
// Licensed under the MIT License. See License.txt in the project root for license information.
3+
4+
using System;
5+
using Microsoft.Extensions.Logging;
6+
7+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
8+
{
9+
internal class LinuxAppServiceEventGenerator : LinuxEventGenerator
10+
{
11+
private readonly LinuxAppServiceFileLoggerFactory _loggerFactory;
12+
13+
public LinuxAppServiceEventGenerator(LinuxAppServiceFileLoggerFactory loggerFactory)
14+
{
15+
_loggerFactory = loggerFactory;
16+
}
17+
18+
public static string TraceEventRegex { get; } = $"(?<Level>[0-6]),(?<SubscriptionId>[^,]*),(?<AppName>[^,]*),(?<FunctionName>[^,]*),(?<EventName>[^,]*),(?<Source>[^,]*),\"(?<Details>.*)\",\"(?<Summary>.*)\",(?<HostVersion>[^,]*),(?<EventTimestamp>[^,]+),(?<ExceptionType>[^,]*),\"(?<ExceptionMessage>.*)\",(?<FunctionInvocationId>[^,]*),(?<HostInstanceId>[^,]*),(?<ActivityId>[^,\"]*)";
19+
20+
public static string MetricEventRegex { get; } = $"(?<SubscriptionId>[^,]*),(?<AppName>[^,]*),(?<FunctionName>[^,]*),(?<EventName>[^,]*),(?<Average>\\d*),(?<Min>\\d*),(?<Max>\\d*),(?<Count>\\d*),(?<HostVersion>[^,]*),(?<EventTimestamp>[^,\"]+)";
21+
22+
public static string DetailsEventRegex { get; } = $"(?<AppName>[^,]*),(?<FunctionName>[^,]*),\"(?<InputBindings>.*)\",\"(?<OutputBindings>.*)\",(?<ScriptType>[^,]*),(?<IsDisabled>[0|1])";
23+
24+
public override void LogFunctionTraceEvent(LogLevel level, string subscriptionId, string appName, string functionName, string eventName,
25+
string source, string details, string summary, string exceptionType, string exceptionMessage,
26+
string functionInvocationId, string hostInstanceId, string activityId)
27+
{
28+
var eventTimestamp = DateTime.UtcNow.ToString(EventTimestampFormat);
29+
var hostVersion = ScriptHost.Version;
30+
FunctionsSystemLogsEventSource.Instance.SetActivityId(activityId);
31+
32+
var logger = _loggerFactory.GetOrCreate(FunctionsLogsCategory);
33+
WriteEvent(logger, $"{(int)ToEventLevel(level)},{subscriptionId},{appName},{functionName},{eventName},{source},{NormalizeString(details)},{NormalizeString(summary)},{hostVersion},{eventTimestamp},{exceptionType},{NormalizeString(exceptionMessage)},{functionInvocationId},{hostInstanceId},{activityId}");
34+
}
35+
36+
public override void LogFunctionMetricEvent(string subscriptionId, string appName, string functionName, string eventName, long average,
37+
long minimum, long maximum, long count, DateTime eventTimestamp)
38+
{
39+
var hostVersion = ScriptHost.Version;
40+
var logger = _loggerFactory.GetOrCreate(FunctionsMetricsCategory);
41+
WriteEvent(logger, $"{subscriptionId},{appName},{functionName},{eventName},{average},{minimum},{maximum},{count},{hostVersion},{eventTimestamp.ToString(EventTimestampFormat)}");
42+
}
43+
44+
public override void LogFunctionDetailsEvent(string siteName, string functionName, string inputBindings, string outputBindings,
45+
string scriptType, bool isDisabled)
46+
{
47+
var logger = _loggerFactory.GetOrCreate(FunctionsDetailsCategory);
48+
WriteEvent(logger, $"{siteName},{functionName},{NormalizeString(inputBindings)},{NormalizeString(outputBindings)},{scriptType},{(isDisabled ? 1 : 0)}");
49+
}
50+
51+
public override void LogFunctionExecutionAggregateEvent(string siteName, string functionName, long executionTimeInMs,
52+
long functionStartedCount, long functionCompletedCount, long functionFailedCount)
53+
{
54+
}
55+
56+
public override void LogFunctionExecutionEvent(string executionId, string siteName, int concurrency, string functionName,
57+
string invocationId, string executionStage, long executionTimeSpan, bool success)
58+
{
59+
}
60+
61+
private static void WriteEvent(LinuxAppServiceFileLogger logger, string evt)
62+
{
63+
logger.Log(evt);
64+
}
65+
}
66+
}
Lines changed: 173 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,173 @@
1+
// Copyright (c) .NET Foundation. All rights reserved.
2+
// Licensed under the MIT License. See License.txt in the project root for license information.
3+
4+
using System;
5+
using System.Collections.Concurrent;
6+
using System.Collections.Generic;
7+
using System.IO;
8+
using System.IO.Abstractions;
9+
using System.Linq;
10+
using System.Threading;
11+
using System.Threading.Tasks;
12+
13+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
14+
{
15+
public class LinuxAppServiceFileLogger
16+
{
17+
private readonly string _logFileName;
18+
private readonly string _logFileDirectory;
19+
private readonly string _logFilePath;
20+
private readonly BlockingCollection<string> _buffer;
21+
private readonly List<string> _currentBatch;
22+
private readonly IFileSystem _fileSystem;
23+
private readonly CancellationTokenSource _cancellationTokenSource;
24+
private Task _outputTask;
25+
26+
public LinuxAppServiceFileLogger(string logFileName, string logFileDirectory, IFileSystem fileSystem, bool startOnCreate = true)
27+
{
28+
_logFileName = logFileName;
29+
_logFileDirectory = logFileDirectory;
30+
_logFilePath = Path.Combine(_logFileDirectory, _logFileName + ".log");
31+
_buffer = new BlockingCollection<string>(new ConcurrentQueue<string>());
32+
_currentBatch = new List<string>();
33+
_fileSystem = fileSystem;
34+
_cancellationTokenSource = new CancellationTokenSource();
35+
36+
if (startOnCreate)
37+
{
38+
Start();
39+
}
40+
}
41+
42+
// Maximum number of files
43+
public int MaxFileCount { get; set; } = 3;
44+
45+
// Maximum size of individual log file in MB
46+
public int MaxFileSizeMb { get; set; } = 10;
47+
48+
// Maximum time between successive flushes (seconds)
49+
public int FlushFrequencySeconds { get; set; } = 30;
50+
51+
public virtual void Log(string message)
52+
{
53+
try
54+
{
55+
_buffer.Add(message);
56+
}
57+
catch (Exception)
58+
{
59+
// ignored
60+
}
61+
}
62+
63+
public void Start()
64+
{
65+
if (_outputTask == null)
66+
{
67+
_outputTask = Task.Factory.StartNew(ProcessLogQueue, null, TaskCreationOptions.LongRunning);
68+
}
69+
}
70+
71+
public void Stop(TimeSpan timeSpan)
72+
{
73+
_cancellationTokenSource.Cancel();
74+
75+
try
76+
{
77+
_outputTask?.Wait(timeSpan);
78+
}
79+
catch (Exception)
80+
{
81+
// ignored
82+
}
83+
}
84+
85+
public virtual async Task ProcessLogQueue(object state)
86+
{
87+
while (!_cancellationTokenSource.IsCancellationRequested)
88+
{
89+
await InternalProcessLogQueue();
90+
await Task.Delay(TimeSpan.FromSeconds(FlushFrequencySeconds), _cancellationTokenSource.Token).ContinueWith(task => { });
91+
}
92+
// ReSharper disable once FunctionNeverReturns
93+
}
94+
95+
// internal for unittests
96+
internal async Task InternalProcessLogQueue()
97+
{
98+
string currentMessage;
99+
while (_buffer.TryTake(out currentMessage))
100+
{
101+
_currentBatch.Add(currentMessage);
102+
}
103+
104+
if (_currentBatch.Any())
105+
{
106+
try
107+
{
108+
await WriteLogs(_currentBatch);
109+
}
110+
catch (Exception)
111+
{
112+
// Ignored
113+
}
114+
115+
_currentBatch.Clear();
116+
}
117+
}
118+
119+
private async Task WriteLogs(IEnumerable<string> currentBatch)
120+
{
121+
_fileSystem.Directory.CreateDirectory(_logFileDirectory);
122+
123+
var fileInfo = _fileSystem.FileInfo.FromFileName(_logFilePath);
124+
if (fileInfo.Exists)
125+
{
126+
if (fileInfo.Length / (1024 * 1024) >= MaxFileSizeMb)
127+
{
128+
RollFiles();
129+
}
130+
}
131+
132+
await AppendLogs(_logFilePath, currentBatch);
133+
}
134+
135+
private async Task AppendLogs(string filePath, IEnumerable<string> logs)
136+
{
137+
using (var streamWriter = _fileSystem.File.AppendText(filePath))
138+
{
139+
foreach (var log in logs)
140+
{
141+
await streamWriter.WriteLineAsync(log);
142+
}
143+
}
144+
}
145+
146+
private void RollFiles()
147+
{
148+
// Rename current file to older file.
149+
// Empty current file.
150+
// Delete oldest file if exceeded configured max no. of files.
151+
152+
_fileSystem.File.Move(_logFilePath, GetCurrentFileName(DateTime.UtcNow));
153+
154+
var fileInfoBases = ListFiles(_logFileDirectory, _logFileName + "*", SearchOption.TopDirectoryOnly);
155+
156+
if (fileInfoBases.Length >= MaxFileCount)
157+
{
158+
var oldestFile = fileInfoBases.OrderByDescending(f => f.Name).Last();
159+
oldestFile.Delete();
160+
}
161+
}
162+
163+
private FileInfoBase[] ListFiles(string directoryPath, string pattern, SearchOption searchOption)
164+
{
165+
return _fileSystem.DirectoryInfo.FromDirectoryName(directoryPath).GetFiles(pattern, searchOption);
166+
}
167+
168+
public string GetCurrentFileName(DateTime dateTime)
169+
{
170+
return Path.Combine(_logFileDirectory, $"{_logFileName}{dateTime:yyyyMMddHHmmss}.log");
171+
}
172+
}
173+
}
Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,26 @@
1+
// Copyright (c) .NET Foundation. All rights reserved.
2+
// Licensed under the MIT License. See License.txt in the project root for license information.
3+
4+
using System;
5+
using System.Collections.Concurrent;
6+
using System.IO.Abstractions;
7+
8+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
9+
{
10+
public class LinuxAppServiceFileLoggerFactory
11+
{
12+
private static readonly ConcurrentDictionary<string, Lazy<LinuxAppServiceFileLogger>> Loggers = new ConcurrentDictionary<string, Lazy<LinuxAppServiceFileLogger>>();
13+
private readonly string _logRootPath;
14+
15+
public LinuxAppServiceFileLoggerFactory()
16+
{
17+
_logRootPath = Environment.GetEnvironmentVariable(EnvironmentSettingNames.FunctionsLogsMountPath);
18+
}
19+
20+
public virtual LinuxAppServiceFileLogger GetOrCreate(string category)
21+
{
22+
return Loggers.GetOrAdd(category,
23+
c => new Lazy<LinuxAppServiceFileLogger>(() => new LinuxAppServiceFileLogger(category, _logRootPath, new FileSystem()))).Value;
24+
}
25+
}
26+
}

src/WebJobs.Script.WebHost/Diagnostics/LinuxContainerEventGenerator.cs

Lines changed: 6 additions & 46 deletions
Original file line numberDiff line numberDiff line change
@@ -2,14 +2,12 @@
22
// Licensed under the MIT License. See License.txt in the project root for license information.
33

44
using System;
5-
using System.Diagnostics.Tracing;
65
using Microsoft.Extensions.Logging;
76

87
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
98
{
10-
internal class LinuxContainerEventGenerator : IEventGenerator
9+
internal class LinuxContainerEventGenerator : LinuxEventGenerator
1110
{
12-
private const string EventTimestampFormat = "MM/dd/yyyy hh:mm:ss.fff tt";
1311
private readonly Action<string> _writeEvent;
1412
private readonly bool _consoleEnabled = true;
1513

@@ -31,7 +29,7 @@ public LinuxContainerEventGenerator(Action<string> writeEvent = null)
3129

3230
public static string DetailsEventRegex { get; } = $"{ScriptConstants.LinuxFunctionDetailsEventStreamName} (?<AppName>[^,]*),(?<FunctionName>[^,]*),\\\\\"(?<InputBindings>.*)\\\\\",\\\\\"(?<OutputBindings>.*)\\\\\",(?<ScriptType>[^,]*),(?<IsDisabled>[0|1])";
3331

34-
public void LogFunctionTraceEvent(LogLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary, string exceptionType, string exceptionMessage, string functionInvocationId, string hostInstanceId, string activityId)
32+
public override void LogFunctionTraceEvent(LogLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary, string exceptionType, string exceptionMessage, string functionInvocationId, string hostInstanceId, string activityId)
3533
{
3634
string eventTimestamp = DateTime.UtcNow.ToString(EventTimestampFormat);
3735
string hostVersion = ScriptHost.Version;
@@ -40,23 +38,23 @@ public void LogFunctionTraceEvent(LogLevel level, string subscriptionId, string
4038
_writeEvent($"{ScriptConstants.LinuxLogEventStreamName} {(int)ToEventLevel(level)},{subscriptionId},{appName},{functionName},{eventName},{source},{NormalizeString(details)},{NormalizeString(summary)},{hostVersion},{eventTimestamp},{exceptionType},{NormalizeString(exceptionMessage)},{functionInvocationId},{hostInstanceId},{activityId}");
4139
}
4240

43-
public void LogFunctionMetricEvent(string subscriptionId, string appName, string functionName, string eventName, long average, long minimum, long maximum, long count, DateTime eventTimestamp)
41+
public override void LogFunctionMetricEvent(string subscriptionId, string appName, string functionName, string eventName, long average, long minimum, long maximum, long count, DateTime eventTimestamp)
4442
{
4543
string hostVersion = ScriptHost.Version;
4644

4745
_writeEvent($"{ScriptConstants.LinuxMetricEventStreamName} {subscriptionId},{appName},{functionName},{eventName},{average},{minimum},{maximum},{count},{hostVersion},{eventTimestamp.ToString(EventTimestampFormat)}");
4846
}
4947

50-
public void LogFunctionDetailsEvent(string siteName, string functionName, string inputBindings, string outputBindings, string scriptType, bool isDisabled)
48+
public override void LogFunctionDetailsEvent(string siteName, string functionName, string inputBindings, string outputBindings, string scriptType, bool isDisabled)
5149
{
5250
_writeEvent($"{ScriptConstants.LinuxFunctionDetailsEventStreamName} {siteName},{functionName},{NormalizeString(inputBindings)},{NormalizeString(outputBindings)},{scriptType},{(isDisabled ? 1 : 0)}");
5351
}
5452

55-
public void LogFunctionExecutionAggregateEvent(string siteName, string functionName, long executionTimeInMs, long functionStartedCount, long functionCompletedCount, long functionFailedCount)
53+
public override void LogFunctionExecutionAggregateEvent(string siteName, string functionName, long executionTimeInMs, long functionStartedCount, long functionCompletedCount, long functionFailedCount)
5654
{
5755
}
5856

59-
public void LogFunctionExecutionEvent(string executionId, string siteName, int concurrency, string functionName, string invocationId, string executionStage, long executionTimeSpan, bool success)
57+
public override void LogFunctionExecutionEvent(string executionId, string siteName, int concurrency, string functionName, string invocationId, string executionStage, long executionTimeSpan, bool success)
6058
{
6159
}
6260

@@ -67,43 +65,5 @@ private void ConsoleWriter(string evt)
6765
Console.WriteLine(evt);
6866
}
6967
}
70-
71-
internal static string NormalizeString(string value)
72-
{
73-
// need to remove newlines for csv output
74-
value = value.Replace(Environment.NewLine, " ");
75-
76-
// Wrap string literals in enclosing quotes
77-
// For string columns that may contain quotes and/or
78-
// our delimiter ',', before writing the value we
79-
// enclose in quotes. This allows us to define matching
80-
// groups based on quotes for these values.
81-
return $"\"{value}\"";
82-
}
83-
84-
/// <summary>
85-
/// Performs the same mapping from <see cref="LogLevel"/> to <see cref="EventLevel"/>
86-
/// that is performed for ETW event logging in <see cref="EtwEventGenerator"/>, so we
87-
/// have consistent log levels across platforms.
88-
/// </summary>
89-
internal static EventLevel ToEventLevel(LogLevel level)
90-
{
91-
switch (level)
92-
{
93-
case LogLevel.Trace:
94-
case LogLevel.Debug:
95-
return EventLevel.Verbose;
96-
case LogLevel.Information:
97-
return EventLevel.Informational;
98-
case LogLevel.Warning:
99-
return EventLevel.Warning;
100-
case LogLevel.Error:
101-
return EventLevel.Error;
102-
case LogLevel.Critical:
103-
return EventLevel.Critical;
104-
default:
105-
return EventLevel.LogAlways;
106-
}
107-
}
10868
}
10969
}

0 commit comments

Comments
 (0)