Skip to content

Commit 7e6f825

Browse files
brettsambrettsam
committed
Sanitizing system logs
1 parent 63251fd commit 7e6f825

File tree

10 files changed

+131
-29
lines changed

10 files changed

+131
-29
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

‎src/WebJobs.Script.WebHost/Diagnostics/Sanitizer.cs‎

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.WebHost/WebJobs.Script.WebHost.csproj‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -421,6 +421,7 @@
421421
<Compile Include="App_Start\WebApiConfig.cs" />
422422
<Compile Include="App_Start\WebHostResolver.cs" />
423423
<Compile Include="App_Start\WebHostSettings.cs" />
424+
<Compile Include="Diagnostics\Sanitizer.cs" />
424425
<Compile Include="StandbyManager.cs" />
425426
<Compile Include="Controllers\AdminController.cs" />
426427
<Compile Include="Controllers\FunctionsController.cs" />

‎src/WebJobs.Script/Host/ScriptHost.cs‎

Lines changed: 26 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,12 @@ public class ScriptHost : JobHost
4545
private const string GeneratedTypeNamespace = "Host";
4646
internal const string GeneratedTypeName = "Functions";
4747
private readonly IScriptHostEnvironment _scriptHostEnvironment;
48+
private static readonly string[] WellKnownHostJsonProperties = new[]
49+
{
50+
"id", "functionTimeout", "http", "watchDirectories", "functions", "queues", "serviceBus",
51+
"eventHub", "tracing", "singleton", "logger", "aggregator", "applicationInsights"
52+
};
53+
4854
private string _instanceId;
4955
private Func<Task> _restart;
5056
private Action _shutdown;
@@ -343,10 +349,6 @@ protected virtual void Initialize()
343349
TraceWriter.Info(readingFileMessage);
344350

345351
string json = File.ReadAllText(hostConfigFilePath);
346-
347-
string readFileMessage = $"Host configuration file read:{Environment.NewLine}{json}";
348-
TraceWriter.Info(readFileMessage);
349-
350352
JObject hostConfigObject;
351353
try
352354
{
@@ -360,11 +362,14 @@ protected virtual void Initialize()
360362
ConfigureDefaultLoggerFactory();
361363
ILogger startupErrorLogger = _hostConfig.LoggerFactory.CreateLogger(LogCategories.Startup);
362364
startupErrorLogger.LogInformation(readingFileMessage);
363-
startupErrorLogger.LogInformation(readFileMessage);
364365

365366
throw new FormatException(string.Format("Unable to parse {0} file.", ScriptConstants.HostMetadataFileName), ex);
366367
}
367368

369+
string sanitizedJson = SanitizeHostJson(hostConfigObject);
370+
string readFileMessage = $"Host configuration file read:{Environment.NewLine}{sanitizedJson}";
371+
TraceWriter.Info(readFileMessage);
372+
368373
try
369374
{
370375
ApplyConfiguration(hostConfigObject, ScriptConfig);
@@ -527,6 +532,22 @@ protected virtual void Initialize()
527532
}
528533
}
529534

535+
internal static string SanitizeHostJson(JObject hostJsonObject)
536+
{
537+
JObject sanitizedObject = new JObject();
538+
539+
foreach (var propName in WellKnownHostJsonProperties)
540+
{
541+
var propValue = hostJsonObject[propName];
542+
if (propValue != null)
543+
{
544+
sanitizedObject[propName] = propValue;
545+
}
546+
}
547+
548+
return sanitizedObject.ToString();
549+
}
550+
530551
// Validate that for any precompiled assembly, all functions have the same configuration precedence.
531552
private void VerifyPrecompileStatus(IEnumerable<FunctionDescriptor> functions)
532553
{

‎test/WebJobs.Script.Tests.Integration/Host/StandbyManagerTests.cs‎

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -31,7 +31,7 @@ public StandbyManagerTests()
3131
public void IsWarmUpRequest_ReturnsExpectedValue()
3232
{
3333
var request = new HttpRequestMessage(HttpMethod.Post, "http://azure.com/api/warmup");
34-
Assert.False(StandbyManager.IsWarmUpRequest(request));
34+
Assert.False(StandbyManager.IsWarmUpRequest(request), "Initial request to 'warmup'.");
3535

3636
var vars = new Dictionary<string, string>
3737
{
@@ -41,20 +41,20 @@ public void IsWarmUpRequest_ReturnsExpectedValue()
4141
using (var env = new TestScopedEnvironmentVariable(vars))
4242
{
4343
_settingsManager.SetSetting(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1");
44-
Assert.False(StandbyManager.IsWarmUpRequest(request));
44+
Assert.False(StandbyManager.IsWarmUpRequest(request), "Set PlaceholderMode to '1'.");
4545

4646
_settingsManager.SetSetting(EnvironmentSettingNames.AzureWebsiteInstanceId, "12345");
47-
Assert.True(StandbyManager.IsWarmUpRequest(request));
47+
Assert.True(StandbyManager.IsWarmUpRequest(request), "Set InstanceId to '12345'.");
4848

4949
request = new HttpRequestMessage(HttpMethod.Post, "http://azure.com/api/csharphttpwarmup");
50-
Assert.True(StandbyManager.IsWarmUpRequest(request));
50+
Assert.True(StandbyManager.IsWarmUpRequest(request), "Request to 'csharpwarmup'.");
5151

5252
request = new HttpRequestMessage(HttpMethod.Post, "http://azure.com/api/warmup");
5353
request.Headers.Add(ScriptConstants.AntaresLogIdHeaderName, "xyz123");
54-
Assert.False(StandbyManager.IsWarmUpRequest(request));
54+
Assert.False(StandbyManager.IsWarmUpRequest(request), "Request to 'warmup'.");
5555

5656
request = new HttpRequestMessage(HttpMethod.Post, "http://azure.com/api/foo");
57-
Assert.False(StandbyManager.IsWarmUpRequest(request));
57+
Assert.False(StandbyManager.IsWarmUpRequest(request), "Request to 'foo'.");
5858
}
5959
}
6060

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

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

422422
public List<string> Events { get; private set; }
423423

424-
public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary, Exception exception = null)
424+
public void LogFunctionTraceEvent(TraceLevel level, string subscriptionId, string appName, string functionName, string eventName, string source, string details, string summary)
425425
{
426426
var elements = new string[] { level.ToString(), subscriptionId, appName, functionName, eventName, source, summary, details };
427427
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
@@ -46,7 +46,7 @@ public void Trace_Verbose_EmitsExpectedEvent()
4646
traceEvent.Properties.Add(ScriptConstants.TracePropertyFunctionNameKey, functionName);
4747
traceEvent.Properties.Add(ScriptConstants.TracePropertyEventDetailsKey, details);
4848

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

5151
_traceWriter.Trace(traceEvent);
5252

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

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

7198
_traceWriter.Trace(traceEvent);
7299

‎test/WebJobs.Script.Tests/ScriptHostTests.cs‎

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

10541054
[Fact]
1055-
public void Initialize_LogsHostJson_IfParseError()
1055+
public void Initialize_LogsException_IfParseError()
10561056
{
10571057
TestLoggerProvider loggerProvider = null;
10581058
var loggerFactoryHookMock = new Mock<ILoggerFactoryBuilder>(MockBehavior.Strict);
@@ -1087,11 +1087,9 @@ public void Initialize_LogsHostJson_IfParseError()
10871087

10881088
// We should have gotten sone messages.
10891089
var logger = loggerProvider.CreatedLoggers.Single();
1090-
Assert.Equal(3, logger.LogMessages.Count);
1091-
Assert.StartsWith("Reading host configuration file", logger.LogMessages[0].FormattedMessage);
1092-
Assert.StartsWith("Host configuration file read", logger.LogMessages[1].FormattedMessage);
1093-
Assert.StartsWith("ScriptHost initialization failed", logger.LogMessages[2].FormattedMessage);
1094-
Assert.Equal("Unable to parse host.json file.", logger.LogMessages[2].Exception.Message);
1090+
Assert.Equal(2, logger.LogMessages.Count);
1091+
Assert.StartsWith("ScriptHost initialization failed", logger.LogMessages[1].FormattedMessage);
1092+
Assert.Equal("Unable to parse host.json file.", logger.LogMessages[1].Exception.Message);
10951093
}
10961094

10971095
[Fact]

0 commit comments

Comments
 (0)