Skip to content

Commit 56f7ef5

Browse files
brettsambrettsam
committed
adding DeferredLogger to send WebHost logs to JobHost
1 parent b8fd814 commit 56f7ef5

32 files changed

+589
-213
lines changed

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

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,6 @@
88
using Microsoft.Azure.WebJobs.Script.Diagnostics;
99
using Microsoft.Azure.WebJobs.Script.Eventing;
1010
using Microsoft.Azure.WebJobs.Script.FileProvisioning;
11-
using Microsoft.Azure.WebJobs.Script.Rpc;
1211
using Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics;
1312
using Microsoft.Extensions.DependencyInjection;
1413
using Microsoft.Extensions.Hosting;
@@ -44,7 +43,7 @@ private static ExpectedDependencyBuilder CreateExpectedDependencies()
4443
.Expect<PrimaryHostCoordinator>()
4544
.Expect<HttpInitializationService>()
4645
.Expect<FileMonitoringService>()
47-
.Expect<LanguageWorkerConsoleLogService>()
46+
.Expect<DeferredLoggerService>()
4847
.Optional<FuncAppFileProvisioningService>() // Used by powershell.
4948
.Optional<JobHostService>() // Missing when host is offline.
5049
.Optional<FunctionsSyncService>(); // Conditionally registered.

‎src/WebJobs.Script.WebHost/Diagnostics/DeferredLogger/DeferredLogMessage.cs‎

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,28 @@
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.Generic;
6+
using Microsoft.Extensions.Logging;
7+
8+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
9+
{
10+
public class DeferredLogMessage
11+
{
12+
public DateTimeOffset Timestamp { get; internal set; }
13+
14+
public LogLevel LogLevel { get; internal set; }
15+
16+
public EventId EventId { get; internal set; }
17+
18+
public object State { get; internal set; }
19+
20+
public Exception Exception { get; internal set; }
21+
22+
public Func<object, Exception, string> Formatter { get; internal set; }
23+
24+
public string Category { get; internal set; }
25+
26+
public IEnumerable<object> Scope { get; internal set; }
27+
}
28+
}

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

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,62 @@
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.Generic;
6+
using System.Threading.Channels;
7+
using Microsoft.Extensions.Logging;
8+
9+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
10+
{
11+
internal class DeferredLogger : ILogger
12+
{
13+
private readonly string _category;
14+
private readonly ChannelWriter<DeferredLogMessage> _buffer;
15+
private readonly IExternalScopeProvider _scopeProvider;
16+
17+
public DeferredLogger(string category, ChannelWriter<DeferredLogMessage> buffer, IExternalScopeProvider scopeProvider)
18+
{
19+
_category = category ?? throw new ArgumentNullException(nameof(category));
20+
_buffer = buffer ?? throw new ArgumentNullException(nameof(buffer));
21+
_scopeProvider = scopeProvider ?? throw new ArgumentNullException(nameof(scopeProvider));
22+
}
23+
24+
public IDisposable BeginScope<TState>(TState state) => _scopeProvider.Push(state);
25+
26+
public bool IsEnabled(LogLevel logLevel) => true;
27+
28+
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
29+
{
30+
if (!IsEnabled(logLevel))
31+
{
32+
return;
33+
}
34+
35+
string StateFormatter(object s, Exception e)
36+
{
37+
TState castState = (TState)s;
38+
return formatter?.Invoke(castState, e);
39+
}
40+
41+
IList<object> scopeList = new List<object>();
42+
_scopeProvider.ForEachScope((scope, s) =>
43+
{
44+
s.Add(scope);
45+
}, scopeList);
46+
47+
DeferredLogMessage logMessage = new DeferredLogMessage
48+
{
49+
Timestamp = DateTimeOffset.UtcNow,
50+
Category = _category,
51+
LogLevel = logLevel,
52+
EventId = eventId,
53+
State = state,
54+
Exception = exception,
55+
Formatter = StateFormatter,
56+
Scope = scopeList
57+
};
58+
59+
_buffer.TryWrite(logMessage);
60+
}
61+
}
62+
}

‎src/WebJobs.Script.WebHost/Diagnostics/DeferredLogger/DeferredLoggerProvider.cs‎

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,50 @@
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.Threading.Channels;
5+
using Microsoft.Extensions.Logging;
6+
7+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
8+
{
9+
internal class DeferredLoggerProvider : ILoggerProvider, IDeferredLogSource, ISupportExternalScope
10+
{
11+
private readonly Channel<DeferredLogMessage> _loggerChannel;
12+
13+
private IExternalScopeProvider _scopeProvider;
14+
private bool _disposed;
15+
16+
public DeferredLoggerProvider()
17+
: this(1000)
18+
{
19+
}
20+
21+
internal DeferredLoggerProvider(int bufferSize)
22+
{
23+
_loggerChannel = Channel.CreateBounded<DeferredLogMessage>(new BoundedChannelOptions(bufferSize)
24+
{
25+
FullMode = BoundedChannelFullMode.DropWrite,
26+
AllowSynchronousContinuations = true,
27+
SingleWriter = true,
28+
SingleReader = false
29+
});
30+
}
31+
32+
public ChannelReader<DeferredLogMessage> LogChannel => _loggerChannel.Reader;
33+
34+
public ILogger CreateLogger(string categoryName) => new DeferredLogger(categoryName, _loggerChannel.Writer, _scopeProvider);
35+
36+
public void SetScopeProvider(IExternalScopeProvider scopeProvider)
37+
{
38+
_scopeProvider = scopeProvider;
39+
}
40+
41+
public void Dispose()
42+
{
43+
if (!_disposed)
44+
{
45+
_loggerChannel.Writer.Complete();
46+
_disposed = true;
47+
}
48+
}
49+
}
50+
}

‎src/WebJobs.Script.WebHost/Diagnostics/DeferredLogger/DeferredLoggerService.cs‎

Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,88 @@
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.Generic;
6+
using System.Linq;
7+
using System.Reactive.Disposables;
8+
using System.Threading;
9+
using System.Threading.Channels;
10+
using System.Threading.Tasks;
11+
using Microsoft.Extensions.Hosting;
12+
using Microsoft.Extensions.Logging;
13+
14+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
15+
{
16+
internal class DeferredLoggerService : IHostedService
17+
{
18+
private readonly ILoggerFactory _loggerFactory;
19+
private readonly IDeferredLogSource _deferredLogSource;
20+
private readonly CancellationTokenSource _cts = new CancellationTokenSource();
21+
22+
private Task _processingTask;
23+
24+
public DeferredLoggerService(IDeferredLogSource deferredLogSource, ILoggerFactory loggerFactory)
25+
{
26+
_loggerFactory = loggerFactory;
27+
_deferredLogSource = deferredLogSource;
28+
}
29+
30+
public Task StartAsync(CancellationToken cancellationToken)
31+
{
32+
_processingTask = ProcessLogsAsync();
33+
return Task.CompletedTask;
34+
}
35+
36+
private void OnDeferredLog(DeferredLogMessage message)
37+
{
38+
ILogger logger = _loggerFactory.CreateLogger(message.Category);
39+
40+
using (RecreateCapturedScope(logger, message.Scope))
41+
{
42+
logger.Log(message.LogLevel, message.EventId, message.State, message.Exception, message.Formatter);
43+
}
44+
}
45+
46+
private IDisposable RecreateCapturedScope(ILogger logger, IEnumerable<object> scope)
47+
{
48+
IList<IDisposable> disposableScopes = scope.Select(s => logger.BeginScope(s)).ToList();
49+
50+
// Allow loggers to know that these logs are deferred.
51+
disposableScopes.Add(logger.BeginScope(new Dictionary<string, object>
52+
{
53+
{ ScriptConstants.LoggerDeferredLog, true },
54+
}));
55+
56+
return Disposable.Create(() =>
57+
{
58+
foreach (IDisposable disposable in disposableScopes.Reverse())
59+
{
60+
disposable.Dispose();
61+
}
62+
});
63+
}
64+
65+
private async Task ProcessLogsAsync()
66+
{
67+
ChannelReader<DeferredLogMessage> channelReader = _deferredLogSource.LogChannel;
68+
69+
try
70+
{
71+
while (await channelReader.WaitToReadAsync(_cts.Token))
72+
{
73+
OnDeferredLog(await channelReader.ReadAsync(_cts.Token));
74+
}
75+
}
76+
catch (OperationCanceledException)
77+
{
78+
// This happens when StopAsync is called.
79+
}
80+
}
81+
82+
public async Task StopAsync(CancellationToken cancellationToken)
83+
{
84+
_cts.Cancel();
85+
await _processingTask;
86+
}
87+
}
88+
}

‎src/WebJobs.Script.WebHost/Diagnostics/DeferredLogger/IDeferredLogSource.cs‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,12 @@
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.Threading.Channels;
5+
6+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
7+
{
8+
public interface IDeferredLogSource
9+
{
10+
ChannelReader<DeferredLogMessage> LogChannel { get; }
11+
}
12+
}

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

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,5 +15,15 @@ public static void AddWebJobsSystem<T>(this ILoggingBuilder builder) where T : S
1515
// Log all logs to SystemLogger
1616
builder.AddDefaultWebJobsFilters<T>(LogLevel.Trace);
1717
}
18+
19+
public static void AddDeferred(this ILoggingBuilder builder)
20+
{
21+
// Do not filter this. It will be filtered internally.
22+
builder.Services.AddSingleton<DeferredLoggerProvider>();
23+
builder.AddFilter<DeferredLoggerProvider>(_ => true);
24+
25+
builder.Services.AddSingleton<ILoggerProvider>(s => s.GetRequiredService<DeferredLoggerProvider>());
26+
builder.Services.AddSingleton<IDeferredLogSource>(s => s.GetRequiredService<DeferredLoggerProvider>());
27+
}
1828
}
1929
}

‎src/WebJobs.Script.WebHost/Middleware/SystemTraceMiddleware.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -42,15 +42,15 @@ public async Task Invoke(HttpContext context)
4242
{
4343
[ScriptConstants.LogPropertyActivityIdKey] = request.GetRequestId()
4444
};
45-
_logger.Log(LogLevel.Information, 0, logData, null, (s, e) => $"Executing HTTP request: {details}");
45+
_logger.Log(LogLevel.Debug, 0, logData, null, (s, e) => $"Executing HTTP request: {details}");
4646

4747
await _next.Invoke(context);
4848

4949
sw.Stop();
5050
details["identities"] = GetIdentities(context);
5151
details["status"] = context.Response.StatusCode;
5252
details["duration"] = sw.ElapsedMilliseconds;
53-
_logger.Log(LogLevel.Information, 0, logData, null, (s, e) => $"Executed HTTP request: {details}");
53+
_logger.Log(LogLevel.Debug, 0, logData, null, (s, e) => $"Executed HTTP request: {details}");
5454
}
5555

5656
internal static void SetRequestId(HttpRequest request)

‎src/WebJobs.Script.WebHost/Program.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,7 @@ public static IWebHostBuilder CreateWebHostBuilder(string[] args = null)
6969

7070
loggingBuilder.AddDefaultWebJobsFilters();
7171
loggingBuilder.AddWebJobsSystem<WebHostSystemLoggerProvider>();
72+
loggingBuilder.AddDeferred();
7273
})
7374
.UseStartup<Startup>();
7475
}

‎src/WebJobs.Script.WebHost/WebScriptHostBuilderExtension.cs‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,9 @@ public static IHostBuilder AddWebScriptHost(this IHostBuilder builder, IServiceP
3434
// must happen before the script host is added below
3535
services.ConfigureOptions<HttpOptionsSetup>();
3636
services.ConfigureOptions<HostHstsOptionsSetup>();
37+
38+
// Add logging service early.
39+
services.AddSingleton<IHostedService, DeferredLoggerService>();
3740
})
3841
.AddScriptHost(webHostOptions, configLoggerFactory, webJobsBuilder =>
3942
{

0 commit comments

Comments
 (0)