Skip to content

Commit defe42b

Browse files
committed
Sanitizing system logs
1 parent 36f37c7 commit defe42b

File tree

8 files changed

+124
-23
lines changed

8 files changed

+124
-23
lines changed

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

Lines changed: 1 addition & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@ internal class EventGenerator : IEventGenerator
1212
{
1313
private const string EventTimestamp = "MM/dd/yyyy hh:mm:ss.fff tt";
1414

15-
public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary, Exception exception = null)
15+
public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary)
1616
{
1717
string eventTimestamp = DateTime.UtcNow.ToString(EventTimestamp);
1818
switch (level)
@@ -27,10 +27,6 @@ public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, strin
2727
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventWarning(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, eventTimestamp);
2828
break;
2929
case TraceLevel.Error:
30-
if (string.IsNullOrEmpty(details) && exception != null)
31-
{
32-
details = exception.ToFormattedString();
33-
}
3430
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventError(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, eventTimestamp);
3531
break;
3632
}

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

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
88
{
99
public interface IEventGenerator
1010
{
11-
void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary, Exception exception = null);
11+
void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary);
1212

1313
void LogFunctionMetricEvent(string subscriptionId, string appName, string functionName, string eventName, long average, long minimum, long maximum, long count, DateTime eventTimestamp);
1414

Lines changed: 53 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,53 @@
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+
6+
namespace Microsoft.Azure.WebJobs.Logging
7+
{
8+
/// <summary>
9+
/// Utility class for sanitizing logging strings.
10+
/// </summary>
11+
// Note: This file is shared between the WebJobs SDK and Script repos. Update both if changes are needed.
12+
internal static class Sanitizer
13+
{
14+
private const string SecretReplacement = "[Hidden Credential]";
15+
private static readonly char[] ValueTerminators = new char[] { '<', '"' };
16+
private static readonly string[] CredentialTokens = new string[] { "Token=", "DefaultEndpointsProtocol=http", "AccountKey=", "Data Source=", "Server=", "Password=", "pwd=", "&amp;sig=" };
17+
18+
/// <summary>
19+
/// Removes well-known credential strings from strings.
20+
/// </summary>
21+
/// <param name="input">The string to sanitize.</param>
22+
/// <returns>The sanitized string.</returns>
23+
internal static string Sanitize(string input)
24+
{
25+
if (input == null)
26+
{
27+
return null;
28+
}
29+
30+
string t = input;
31+
foreach (var token in CredentialTokens)
32+
{
33+
int startIndex = 0;
34+
while (true)
35+
{
36+
// search for the next token instance
37+
startIndex = t.IndexOf(token, startIndex, StringComparison.OrdinalIgnoreCase);
38+
if (startIndex == -1)
39+
{
40+
break;
41+
}
42+
43+
// Find the end of the secret. It most likely ends with either a double quota " or tag opening <
44+
int credentialEnd = t.IndexOfAny(ValueTerminators, startIndex);
45+
46+
t = t.Substring(0, startIndex) + SecretReplacement + (credentialEnd != -1 ? t.Substring(credentialEnd) : string.Empty);
47+
}
48+
}
49+
50+
return t;
51+
}
52+
}
53+
}

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

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
using System;
55
using System.Diagnostics;
66
using Microsoft.Azure.WebJobs.Host;
7+
using Microsoft.Azure.WebJobs.Logging;
78
using Microsoft.Azure.WebJobs.Script.Config;
89

910
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
@@ -35,7 +36,7 @@ public override void Trace(TraceEvent traceEvent)
3536
string subscriptionId = _subscriptionId ?? string.Empty;
3637
string appName = _appName ?? string.Empty;
3738
string source = traceEvent.Source ?? string.Empty;
38-
string summary = traceEvent.Message ?? string.Empty;
39+
string summary = Sanitizer.Sanitize(traceEvent.Message) ?? string.Empty;
3940

4041
// Apply any additional extended event info from the Properties bag
4142
string functionName = string.Empty;
@@ -63,11 +64,16 @@ public override void Trace(TraceEvent traceEvent)
6364

6465
if (traceEvent.Properties.TryGetValue(ScriptConstants.TracePropertyEventDetailsKey, out value) && value != null)
6566
{
66-
details = value.ToString();
67+
details = Sanitizer.Sanitize(value.ToString());
6768
}
6869
}
6970

70-
_eventGenerator.LogFunctionTraceEvent(traceEvent.Level, subscriptionId, appName, functionName, eventName, source, details, summary, traceEvent.Exception);
71+
if (string.IsNullOrEmpty(details) && traceEvent.Exception != null)
72+
{
73+
details = Sanitizer.Sanitize(traceEvent.Exception.ToFormattedString());
74+
}
75+
76+
_eventGenerator.LogFunctionTraceEvent(traceEvent.Level, subscriptionId, appName, functionName, eventName, source, details, summary);
7177
}
7278
}
7379
}

src/WebJobs.Script/Host/ScriptHost.cs

Lines changed: 26 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,12 @@ public class ScriptHost : JobHost
4848
internal const string GeneratedTypeName = "Functions";
4949
private readonly IScriptHostEnvironment _scriptHostEnvironment;
5050
private readonly ILoggerFactoryBuilder _loggerFactoryBuilder;
51+
private static readonly string[] WellKnownHostJsonProperties = new[]
52+
{
53+
"id", "functionTimeout", "http", "watchDirectories", "functions", "queues", "serviceBus",
54+
"eventHub", "tracing", "singleton", "logger", "aggregator", "applicationInsights"
55+
};
56+
5157
private string _instanceId;
5258
private Func<Task> _restart;
5359
private Action _shutdown;
@@ -354,10 +360,6 @@ protected virtual void Initialize()
354360
TraceWriter.Info(readingFileMessage);
355361

356362
string json = File.ReadAllText(hostConfigFilePath);
357-
358-
string readFileMessage = $"Host configuration file read:{Environment.NewLine}{json}";
359-
TraceWriter.Info(readFileMessage);
360-
361363
JObject hostConfigObject;
362364
try
363365
{
@@ -371,11 +373,14 @@ protected virtual void Initialize()
371373
ConfigureDefaultLoggerFactory();
372374
ILogger startupErrorLogger = _hostConfig.LoggerFactory.CreateLogger(LogCategories.Startup);
373375
startupErrorLogger.LogInformation(readingFileMessage);
374-
startupErrorLogger.LogInformation(readFileMessage);
375376

376377
throw new FormatException(string.Format("Unable to parse {0} file.", ScriptConstants.HostMetadataFileName), ex);
377378
}
378379

380+
string sanitizedJson = SanitizeHostJson(hostConfigObject);
381+
string readFileMessage = $"Host configuration file read:{Environment.NewLine}{sanitizedJson}";
382+
TraceWriter.Info(readFileMessage);
383+
379384
try
380385
{
381386
ApplyConfiguration(hostConfigObject, ScriptConfig);
@@ -586,6 +591,22 @@ private static IEnumerable<string> DiscoverBindingTypes(IEnumerable<FunctionMeta
586591
return bindingTypes;
587592
}
588593

594+
internal static string SanitizeHostJson(JObject hostJsonObject)
595+
{
596+
JObject sanitizedObject = new JObject();
597+
598+
foreach (var propName in WellKnownHostJsonProperties)
599+
{
600+
var propValue = hostJsonObject[propName];
601+
if (propValue != null)
602+
{
603+
sanitizedObject[propName] = propValue;
604+
}
605+
}
606+
607+
return sanitizedObject.ToString();
608+
}
609+
589610
// Validate that for any precompiled assembly, all functions have the same configuration precedence.
590611
private void VerifyPrecompileStatus(IEnumerable<FunctionDescriptor> functions)
591612
{

test/WebJobs.Script.Tests.Integration/Host/WebScriptHostManagerTests.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -366,7 +366,7 @@ public TestSystemEventGenerator()
366366

367367
public List<string> Events { get; private set; }
368368

369-
public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary, Exception exception = null)
369+
public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary)
370370
{
371371
var elements = new string[] { level.ToString(), subscriptionId, appName, functionName, eventName, source, summary, details };
372372
string evt = string.Join(" ", elements.Where(p => !string.IsNullOrEmpty(p)));

test/WebJobs.Script.Tests/Diagnostics/SystemTraceWriterTests.cs

Lines changed: 29 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,7 @@ public void Trace_Verbose_EmitsExpectedEvent()
4747
traceEvent.Properties.Add(ScriptConstants.TracePropertyFunctionNameKey, functionName);
4848
traceEvent.Properties.Add(ScriptConstants.TracePropertyEventDetailsKey, details);
4949

50-
_mockEventGenerator.Setup(p => p.LogFunctionTraceEvent(TraceLevel.Verbose, _subscriptionId, _websiteName, functionName, eventName, traceEvent.Source, details, traceEvent.Message, null));
50+
_mockEventGenerator.Setup(p => p.LogFunctionTraceEvent(TraceLevel.Verbose, _subscriptionId, _websiteName, functionName, eventName, traceEvent.Source, details, traceEvent.Message));
5151

5252
_traceWriter.Trace(traceEvent);
5353

@@ -67,7 +67,34 @@ public void Trace_Error_EmitsExpectedEvent()
6767
traceEvent.Properties.Add(ScriptConstants.TracePropertyEventNameKey, eventName);
6868
traceEvent.Properties.Add(ScriptConstants.TracePropertyFunctionNameKey, functionName);
6969

70-
_mockEventGenerator.Setup(p => p.LogFunctionTraceEvent(TraceLevel.Error, _subscriptionId, _websiteName, functionName, eventName, traceEvent.Source, string.Empty, traceEvent.Message, ex));
70+
_mockEventGenerator.Setup(p => p.LogFunctionTraceEvent(TraceLevel.Error, _subscriptionId, _websiteName, functionName, eventName, traceEvent.Source, ex.ToFormattedString(), traceEvent.Message));
71+
72+
_traceWriter.Trace(traceEvent);
73+
74+
_mockEventGenerator.VerifyAll();
75+
}
76+
77+
[Fact]
78+
public void Trace_Sanitizes()
79+
{
80+
string secretReplacement = "[Hidden Credential]";
81+
string secretString = "{ \"AzureWebJobsStorage\": \"DefaultEndpointsProtocol=https;AccountName=testAccount1;AccountKey=mykey1;EndpointSuffix=core.windows.net\", \"AnotherKey\": \"AnotherValue\" }";
82+
string sanitizedString = $"{{ \"AzureWebJobsStorage\": \"{secretReplacement}\", \"AnotherKey\": \"AnotherValue\" }}";
83+
84+
string secretException = "Invalid string: \"DefaultEndpointsProtocol=https;AccountName=testaccount;AccountKey=testkey;BlobEndpoint=https://testaccount.blob.core.windows.net/;QueueEndpoint=https://testaccount.queue.core.windows.net/;TableEndpoint=https://testaccount.table.core.windows.net/;FileEndpoint=https://testaccount.file.core.windows.net/;\"";
85+
string sanitizedException = $"System.InvalidOperationException : Invalid string: \"{secretReplacement}\"";
86+
87+
string functionName = "TestFunction";
88+
string eventName = "TestEvent";
89+
90+
Exception ex = new InvalidOperationException(secretException);
91+
92+
TraceEvent traceEvent = new TraceEvent(TraceLevel.Error, secretString, "TestSource", ex);
93+
94+
traceEvent.Properties.Add(ScriptConstants.TracePropertyEventNameKey, eventName);
95+
traceEvent.Properties.Add(ScriptConstants.TracePropertyFunctionNameKey, functionName);
96+
97+
_mockEventGenerator.Setup(p => p.LogFunctionTraceEvent(TraceLevel.Error, _subscriptionId, _websiteName, functionName, eventName, traceEvent.Source, sanitizedException, sanitizedString));
7198

7299
_traceWriter.Trace(traceEvent);
73100

test/WebJobs.Script.Tests/ScriptHostTests.cs

Lines changed: 4 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1015,7 +1015,7 @@ public void Initialize_AppliesLoggerConfig()
10151015
}
10161016

10171017
[Fact]
1018-
public void Initialize_LogsHostJson_IfParseError()
1018+
public void Initialize_LogsException_IfParseError()
10191019
{
10201020
TestLoggerProvider loggerProvider = null;
10211021
var loggerFactoryHookMock = new Mock<ILoggerFactoryBuilder>(MockBehavior.Strict);
@@ -1048,11 +1048,9 @@ public void Initialize_LogsHostJson_IfParseError()
10481048

10491049
// We should have gotten sone messages.
10501050
var logger = loggerProvider.CreatedLoggers.Single();
1051-
Assert.Equal(3, logger.LogMessages.Count);
1052-
Assert.StartsWith("Reading host configuration file", logger.LogMessages[0].FormattedMessage);
1053-
Assert.StartsWith("Host configuration file read", logger.LogMessages[1].FormattedMessage);
1054-
Assert.StartsWith("ScriptHost initialization failed", logger.LogMessages[2].FormattedMessage);
1055-
Assert.Equal("Unable to parse host.json file.", logger.LogMessages[2].Exception.Message);
1051+
Assert.Equal(2, logger.LogMessages.Count);
1052+
Assert.StartsWith("ScriptHost initialization failed", logger.LogMessages[1].FormattedMessage);
1053+
Assert.Equal("Unable to parse host.json file.", logger.LogMessages[1].Exception.Message);
10561054
}
10571055

10581056
[Fact]

0 commit comments

Comments
 (0)