Skip to content

Commit 826c0b5

Browse files
mathewcmathewc
authored
Throughput improvements (#5601) (#5897)
1 parent 0dc7a7e commit 826c0b5

File tree

135 files changed

+2401
-1422
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

135 files changed

+2401
-1422
lines changed

‎.editorconfig

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,4 @@
1+
[*.cs]
2+
3+
# SA1008: Opening parenthesis should not be preceded by a space.
4+
dotnet_diagnostic.SA1008.severity = silent

‎WebJobs.Script.sln

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -312,6 +312,11 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "WebJobs.Script.Abstractions
312312
EndProject
313313
Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "WebJobsStartupTests", "test\WebJobsStartupTests\WebJobsStartupTests.csproj", "{F5D74052-3807-410F-9A5A-B69A57127CF4}"
314314
EndProject
315+
Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Solution Items", "Solution Items", "{9111825C-9831-4672-8223-82F489853F19}"
316+
ProjectSection(SolutionItems) = preProject
317+
.editorconfig = .editorconfig
318+
EndProjectSection
319+
EndProject
315320
Global
316321
GlobalSection(SharedMSBuildProjectFiles) = preSolution
317322
test\WebJobs.Script.Tests.Shared\WebJobs.Script.Tests.Shared.projitems*{35c9ccb7-d8b6-4161-bb0d-bcfa7c6dcffb}*SharedItemsImports = 13

‎src/WebJobs.Script.Abstractions/WebJobs.Script.Abstractions.csproj

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,9 @@
2424
<TreatWarningsAsErrors>true</TreatWarningsAsErrors>
2525
<WarningsAsErrors />
2626
</PropertyGroup>
27+
<ItemGroup>
28+
<None Include="..\..\.editorconfig" Link=".editorconfig" />
29+
</ItemGroup>
2730

2831
<ItemGroup>
2932
<PackageReference Include="Newtonsoft.Json" Version="11.0.2" />

‎src/WebJobs.Script.WebHost/ContainerManagement/NullLinuxContainerActivityPublisher.cs

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -6,21 +6,21 @@
66
using System.Threading.Tasks;
77
using Microsoft.Azure.WebJobs.Script.WebHost.Models;
88
using Microsoft.Extensions.Hosting;
9-
using Microsoft.Extensions.Logging;
109

1110
namespace Microsoft.Azure.WebJobs.Script.WebHost.ContainerManagement
1211
{
1312
public class NullLinuxContainerActivityPublisher : ILinuxContainerActivityPublisher, IHostedService
1413
{
15-
public NullLinuxContainerActivityPublisher(ILogger<NullLinuxContainerActivityPublisher> logger)
14+
private static readonly Lazy<NullLinuxContainerActivityPublisher> _instance = new Lazy<NullLinuxContainerActivityPublisher>(new NullLinuxContainerActivityPublisher());
15+
16+
private NullLinuxContainerActivityPublisher()
1617
{
17-
var nullLogger = logger ?? throw new ArgumentNullException(nameof(logger));
18-
nullLogger.LogDebug($"Initializing {nameof(NullLinuxContainerActivityPublisher)}");
1918
}
2019

20+
public static NullLinuxContainerActivityPublisher Instance => _instance.Value;
21+
2122
public void PublishFunctionExecutionActivity(ContainerFunctionExecutionActivity activity)
2223
{
23-
//do nothing
2424
}
2525

2626
public Task StartAsync(CancellationToken cancellationToken)

‎src/WebJobs.Script.WebHost/Controllers/HostController.cs

Lines changed: 11 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -12,17 +12,14 @@
1212
using Microsoft.AspNetCore.Http;
1313
using Microsoft.AspNetCore.Mvc;
1414
using Microsoft.AspNetCore.Mvc.WebApiCompatShim;
15-
using Microsoft.Azure.WebJobs.Extensions.Http;
1615
using Microsoft.Azure.WebJobs.Host;
1716
using Microsoft.Azure.WebJobs.Host.Executors;
1817
using Microsoft.Azure.WebJobs.Host.Scale;
1918
using Microsoft.Azure.WebJobs.Script.ExtensionBundle;
2019
using Microsoft.Azure.WebJobs.Script.Scale;
21-
using Microsoft.Azure.WebJobs.Script.WebHost.Authentication;
2220
using Microsoft.Azure.WebJobs.Script.WebHost.Filters;
2321
using Microsoft.Azure.WebJobs.Script.WebHost.Management;
2422
using Microsoft.Azure.WebJobs.Script.WebHost.Models;
25-
using Microsoft.Azure.WebJobs.Script.WebHost.Security.Authorization;
2623
using Microsoft.Azure.WebJobs.Script.WebHost.Security.Authorization.Policies;
2724
using Microsoft.Extensions.DependencyInjection;
2825
using Microsoft.Extensions.Logging;
@@ -40,32 +37,26 @@ namespace Microsoft.Azure.WebJobs.Script.WebHost.Controllers
4037
public class HostController : Controller
4138
{
4239
private readonly IOptions<ScriptApplicationHostOptions> _applicationHostOptions;
43-
private readonly IOptions<JobHostOptions> _hostOptions;
4440
private readonly ILogger _logger;
45-
private readonly IAuthorizationService _authorizationService;
46-
private readonly IWebFunctionsManager _functionsManager;
4741
private readonly IEnvironment _environment;
4842
private readonly IScriptHostManager _scriptHostManager;
4943
private readonly IFunctionsSyncManager _functionsSyncManager;
44+
private readonly HostPerformanceManager _performanceManager;
5045
private static int _warmupExecuted;
5146

5247
public HostController(IOptions<ScriptApplicationHostOptions> applicationHostOptions,
53-
IOptions<JobHostOptions> hostOptions,
5448
ILoggerFactory loggerFactory,
55-
IAuthorizationService authorizationService,
56-
IWebFunctionsManager functionsManager,
5749
IEnvironment environment,
5850
IScriptHostManager scriptHostManager,
59-
IFunctionsSyncManager functionsSyncManager)
51+
IFunctionsSyncManager functionsSyncManager,
52+
HostPerformanceManager performanceManager)
6053
{
6154
_applicationHostOptions = applicationHostOptions;
62-
_hostOptions = hostOptions;
6355
_logger = loggerFactory.CreateLogger(ScriptConstants.LogCategoryHostController);
64-
_authorizationService = authorizationService;
65-
_functionsManager = functionsManager;
6656
_environment = environment;
6757
_scriptHostManager = scriptHostManager;
6858
_functionsSyncManager = functionsSyncManager;
59+
_performanceManager = performanceManager;
6960
}
7061

7162
[HttpGet]
@@ -114,8 +105,14 @@ public async Task<IActionResult> GetHostStatus([FromServices] IScriptHostManager
114105
[HttpPost]
115106
[Route("admin/host/ping")]
116107
[ResponseCache(NoStore = true, Location = ResponseCacheLocation.None)]
117-
public IActionResult Ping([FromServices] IScriptHostManager scriptHostManager)
108+
public async Task<IActionResult> Ping([FromServices] IScriptHostManager scriptHostManager)
118109
{
110+
var result = await _performanceManager.TryHandleHealthPingAsync(HttpContext.Request, _logger);
111+
if (result != null)
112+
{
113+
return result;
114+
}
115+
119116
var pingStatus = new JObject
120117
{
121118
{ "hostState", scriptHostManager.State.ToString() }

‎src/WebJobs.Script.WebHost/DependencyInjection/DependencyValidator/DependencyValidator.cs

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -59,8 +59,7 @@ private static ExpectedDependencyBuilder CreateExpectedDependencies()
5959
.Expect<AzureMonitorDiagnosticLoggerProvider>()
6060
.Expect<FunctionFileLoggerProvider>()
6161
.Expect<HostFileLoggerProvider>()
62-
.Expect<SystemLoggerProvider>()
63-
.Expect<UserLogMetricsLoggerProvider>();
62+
.Expect<SystemLoggerProvider>();
6463

6564
return expected;
6665
}

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

Lines changed: 29 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,6 @@ public class AzureMonitorDiagnosticLogger : ILogger
1919
private readonly string _regionName;
2020
private readonly string _category;
2121
private readonly string _hostInstanceId;
22-
2322
private readonly HostNameProvider _hostNameProvider;
2423
private readonly IEventGenerator _eventGenerator;
2524
private readonly IEnvironment _environment;
@@ -52,29 +51,53 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
5251
return;
5352
}
5453

55-
string formattedMessage = formatter?.Invoke(state, exception);
56-
5754
// Make sure we have something to log
55+
string formattedMessage = formatter?.Invoke(state, exception);
5856
if (string.IsNullOrEmpty(formattedMessage) && exception == null)
5957
{
6058
return;
6159
}
6260

6361
(string exceptionType, string exceptionMessage, string exceptionDetails) = exception.GetExceptionDetails();
62+
if (exception != null)
63+
{
64+
formattedMessage = Sanitizer.Sanitize(formattedMessage);
65+
}
66+
67+
// enumerate all the state values once, capturing the values we'll use below
68+
// last one wins
69+
string stateFunctionName = null;
70+
if (state is IEnumerable<KeyValuePair<string, object>> stateProps)
71+
{
72+
foreach (var kvp in stateProps)
73+
{
74+
if (Utility.IsFunctionName(kvp))
75+
{
76+
stateFunctionName = kvp.Value?.ToString();
77+
}
78+
}
79+
}
6480

6581
var scopeProps = _scopeProvider.GetScopeDictionary();
66-
var stateProps = state as IEnumerable<KeyValuePair<string, object>> ?? new Dictionary<string, object>();
82+
string functionName = stateFunctionName;
83+
if (string.IsNullOrEmpty(functionName))
84+
{
85+
if (Utility.TryGetFunctionName(scopeProps, out string scopeFunctionName))
86+
{
87+
functionName = scopeFunctionName;
88+
}
89+
}
6790

6891
// Build up a JSON string for the Azure Monitor 'properties' bag
6992
StringWriter sw = new StringWriter();
7093
using (JsonTextWriter writer = new JsonTextWriter(sw) { Formatting = Formatting.None })
7194
{
7295
writer.WriteStartObject();
73-
WritePropertyIfNotNull(writer, "message", Sanitizer.Sanitize(formattedMessage));
96+
WritePropertyIfNotNull(writer, "message", formattedMessage);
7497
WritePropertyIfNotNull(writer, "category", _category);
7598
WritePropertyIfNotNull(writer, "hostVersion", _hostVersion);
7699
WritePropertyIfNotNull(writer, "functionInvocationId", Utility.GetValueFromScope(scopeProps, ScopeKeys.FunctionInvocationId));
77-
WritePropertyIfNotNull(writer, "functionName", Utility.ResolveFunctionName(stateProps, scopeProps));
100+
WritePropertyIfNotNull(writer, "functionName", functionName);
78101
WritePropertyIfNotNull(writer, "hostInstanceId", _hostInstanceId);
79102
WritePropertyIfNotNull(writer, "activityId", Utility.GetValueFromScope(scopeProps, ScriptConstants.LogPropertyActivityIdKey));
80103
WritePropertyIfNotNull(writer, "level", logLevel.ToString());

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

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

44
using System;
5-
using System.Runtime.InteropServices.ComTypes;
65
using Microsoft.Extensions.Logging;
76

87
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
@@ -18,25 +17,25 @@ public EtwEventGenerator()
1817
_azureMonitorEventSource = AzureMonitorDiagnosticLogsEventSource.Instance;
1918
}
2019

21-
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, string runtimeSiteName, string slotName)
20+
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, string runtimeSiteName, string slotName, DateTime eventTimeStamp)
2221
{
23-
string eventTimestamp = DateTime.UtcNow.ToString(EventTimestampFormat);
22+
string formattedEventTimestamp = eventTimeStamp.ToString(EventTimestampFormat);
2423
FunctionsSystemLogsEventSource.Instance.SetActivityId(activityId);
2524
switch (level)
2625
{
2726
case LogLevel.Trace:
2827
case LogLevel.Debug:
29-
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventVerbose(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, eventTimestamp, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
28+
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventVerbose(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, formattedEventTimestamp, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
3029
break;
3130
case LogLevel.Information:
32-
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventInfo(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, eventTimestamp, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
31+
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventInfo(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, formattedEventTimestamp, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
3332
break;
3433
case LogLevel.Warning:
35-
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventWarning(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, eventTimestamp, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
34+
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventWarning(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, formattedEventTimestamp, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
3635
break;
3736
case LogLevel.Error:
3837
case LogLevel.Critical:
39-
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventError(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, eventTimestamp, exceptionType, exceptionMessage, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
38+
FunctionsSystemLogsEventSource.Instance.RaiseFunctionsEventError(subscriptionId, appName, functionName, eventName, source, details, summary, ScriptHost.Version, formattedEventTimestamp, exceptionType, exceptionMessage, functionInvocationId, hostInstanceId, runtimeSiteName, slotName);
4039
break;
4140
}
4241
}

‎src/WebJobs.Script.WebHost/Diagnostics/Extensions/ScriptHostServiceLoggerExtension.cs

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

44
using System;
5+
using Microsoft.ApplicationInsights.AspNetCore;
6+
using Microsoft.Azure.Documents;
57
using Microsoft.Extensions.Logging;
68

79
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.Extensions
@@ -162,6 +164,28 @@ public static class ScriptHostServiceLoggerExtension
162164
new EventId(526, nameof(ScriptHostServiceInitCanceledByRuntime)),
163165
"Restart cancellation requested by runtime.");
164166

167+
private static readonly Action<ILogger, string, string, string, string, Exception> _executingHttpRequest =
168+
LoggerMessage.Define<string, string, string, string>(
169+
LogLevel.Information,
170+
new EventId(527, nameof(ExecutingHttpRequest)),
171+
Properties.Resources.ExecutingHttpRequest);
172+
173+
private static readonly Action<ILogger, string, string, int, long, Exception> _executedHttpRequest =
174+
LoggerMessage.Define<string, string, int, long>(
175+
LogLevel.Information,
176+
new EventId(528, nameof(ExecutedHttpRequest)),
177+
Properties.Resources.ExecutedHttpRequest);
178+
179+
public static void ExecutingHttpRequest(this ILogger logger, string mS_ActivityId, string httpMethod, string userAgent, string uri)
180+
{
181+
_executingHttpRequest(logger, mS_ActivityId, httpMethod, userAgent, uri, null);
182+
}
183+
184+
public static void ExecutedHttpRequest(this ILogger logger, string mS_ActivityId, string identities, int statusCode, long duration)
185+
{
186+
_executedHttpRequest(logger, mS_ActivityId, identities, statusCode, duration, null);
187+
}
188+
165189
public static void ScriptHostServiceInitCanceledByRuntime(this ILogger logger)
166190
{
167191
_scriptHostServiceInitCanceledByRuntime(logger, null);

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

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

44
using System;
5-
using System.Collections.Generic;
6-
using System.Linq;
75
using System.Threading;
86
using System.Threading.Tasks;
97
using Microsoft.Azure.Cosmos.Table;
@@ -82,33 +80,31 @@ internal FunctionInstanceLogger(IFunctionMetadataManager metadataManager, IMetri
8280

8381
public async Task AddAsync(FunctionInstanceLogEntry item, CancellationToken cancellationToken = default(CancellationToken))
8482
{
85-
FunctionInstanceMonitor state;
86-
item.Properties.TryGetValue(Key, out state);
83+
FunctionInstanceMonitor monitor;
84+
item.Properties.TryGetValue(Key, out monitor);
8785

8886
if (item.EndTime.HasValue)
8987
{
90-
// Completed
88+
// Function Completed
9189
bool success = item.ErrorDetails == null;
92-
state.End(success);
90+
monitor.End(success);
9391
}
9492
else
9593
{
96-
// Started
97-
if (state == null)
94+
// Function Started
95+
if (monitor == null)
9896
{
99-
string shortName = Utility.GetFunctionShortName(item.FunctionName);
100-
FunctionMetadata function = GetFunctionMetadata(shortName);
101-
102-
if (function == null)
97+
if (_metadataManager.TryGetFunctionMetadata(item.LogName, out FunctionMetadata function))
98+
{
99+
monitor = new FunctionInstanceMonitor(function, _metrics, item.FunctionInstanceId);
100+
item.Properties[Key] = monitor;
101+
monitor.Start();
102+
}
103+
else
103104
{
104105
// This exception will cause the function to not get executed.
105-
throw new InvalidOperationException($"Missing function.json for '{shortName}'.");
106+
throw new InvalidOperationException($"Missing function.json for '{item.LogName}'.");
106107
}
107-
state = new FunctionInstanceMonitor(function, _metrics, item.FunctionInstanceId);
108-
109-
item.Properties[Key] = state;
110-
111-
state.Start();
112108
}
113109
}
114110

@@ -117,7 +113,7 @@ internal FunctionInstanceLogger(IFunctionMetadataManager metadataManager, IMetri
117113
await _writer.AddAsync(new FunctionInstanceLogItem
118114
{
119115
FunctionInstanceId = item.FunctionInstanceId,
120-
FunctionName = Utility.GetFunctionShortName(item.FunctionName),
116+
FunctionName = item.LogName,
121117
StartTime = item.StartTime,
122118
EndTime = item.EndTime,
123119
TriggerReason = item.TriggerReason,
@@ -129,29 +125,19 @@ await _writer.AddAsync(new FunctionInstanceLogItem
129125
}
130126
}
131127

132-
private FunctionMetadata GetFunctionMetadata(string functionName)
133-
{
134-
FunctionMetadata GetMetadataFromCollection(IEnumerable<FunctionMetadata> functions)
135-
{
136-
return functions.FirstOrDefault(p => Utility.FunctionNamesMatch(p.Name, functionName));
137-
}
138-
139-
return GetMetadataFromCollection(_metadataManager.GetFunctionMetadata());
140-
}
141-
142128
public Task FlushAsync(CancellationToken cancellationToken = default(CancellationToken))
143129
{
144130
if (_writer == null)
145131
{
146132
return Task.CompletedTask;
147133
}
134+
148135
return _writer.FlushAsync();
149136
}
150137

151138
public static void OnException(Exception exception, ILogger logger)
152139
{
153-
string errorString = $"Error writing logs to table storage: {exception.ToString()}";
154-
logger.LogError(errorString, exception);
140+
logger.LogError($"Error writing logs to table storage: {exception.ToString()}", exception);
155141
}
156142
}
157143
}

0 commit comments

Comments
 (0)