Skip to content

Commit 14b6b9b

Browse files
committed
Streaming logs and diagnostic events
1 parent 9930104 commit 14b6b9b

16 files changed

+295
-19
lines changed

src/WebJobs.Script/Description/DotNet/Compilation/CSharp/CSharpCompilationService.cs

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -71,10 +71,11 @@ private Compilation GetScriptCompilation(Script<object> script, FunctionMetadata
7171

7272
if (_optimizationLevel == OptimizationLevel.Debug)
7373
{
74-
SyntaxTree scriptTree = compilation.SyntaxTrees.FirstOrDefault(t => string.IsNullOrEmpty(t.FilePath));
74+
string scriptFileName = Path.GetFileName(functionMetadata.ScriptFile);
75+
SyntaxTree scriptTree = compilation.SyntaxTrees.FirstOrDefault(t => string.Equals(t.FilePath, scriptFileName));
7576
var debugTree = SyntaxFactory.SyntaxTree(scriptTree.GetRoot(),
7677
encoding: UTF8WithNoBOM,
77-
path: Path.GetFileName(functionMetadata.ScriptFile),
78+
path: scriptFileName,
7879
options: new CSharpParseOptions(kind: SourceCodeKind.Script));
7980

8081
compilation = compilation

src/WebJobs.Script/Description/DotNet/DotNetFunctionInvoker.cs

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -79,8 +79,7 @@ internal DotNetFunctionInvoker(ScriptHost host,
7979

8080
private static IFunctionMetadataResolver CreateMetadataResolver(ScriptHost host, FunctionMetadata functionMetadata, TraceWriter traceWriter)
8181
{
82-
string functionScriptDirectory = Path.GetDirectoryName(functionMetadata.ScriptFile);
83-
return new FunctionMetadataResolver(functionScriptDirectory, host.ScriptConfig.BindingProviders,
82+
return new FunctionMetadataResolver(functionMetadata.ScriptFile, host.ScriptConfig.BindingProviders,
8483
traceWriter, host.ScriptConfig.HostConfig.LoggerFactory);
8584
}
8685

src/WebJobs.Script/Description/DotNet/FunctionMetadataResolver.cs

Lines changed: 11 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@ public sealed class FunctionMetadataResolver : MetadataReferenceResolver, IFunct
2626
{
2727
private readonly string _privateAssembliesPath;
2828
private readonly string _scriptFileDirectory;
29+
private readonly string _scriptFilePath;
2930
private readonly string[] _assemblyExtensions = new[] { ".exe", ".dll" };
3031
private readonly string _id = Guid.NewGuid().ToString();
3132
private readonly TraceWriter _traceWriter;
@@ -75,12 +76,13 @@ public sealed class FunctionMetadataResolver : MetadataReferenceResolver, IFunct
7576
"Microsoft.Extensions.Logging"
7677
};
7778

78-
public FunctionMetadataResolver(string scriptFileDirectory, ICollection<ScriptBindingProvider> bindingProviders, TraceWriter traceWriter, ILoggerFactory loggerFactory)
79+
public FunctionMetadataResolver(string scriptFilePath, ICollection<ScriptBindingProvider> bindingProviders, TraceWriter traceWriter, ILoggerFactory loggerFactory)
7980
{
80-
_scriptFileDirectory = scriptFileDirectory;
81+
_scriptFileDirectory = Path.GetDirectoryName(scriptFilePath);
82+
_scriptFilePath = scriptFilePath;
8183
_traceWriter = traceWriter;
82-
_packageAssemblyResolver = new PackageAssemblyResolver(scriptFileDirectory);
83-
_privateAssembliesPath = GetBinDirectory(scriptFileDirectory);
84+
_packageAssemblyResolver = new PackageAssemblyResolver(_scriptFileDirectory);
85+
_privateAssembliesPath = GetBinDirectory(_scriptFileDirectory);
8486
_scriptResolver = ScriptMetadataResolver.Default.WithSearchPaths(_privateAssembliesPath);
8587
_extensionSharedAssemblyProvider = new ExtensionSharedAssemblyProvider(bindingProviders);
8688
_loggerFactory = loggerFactory;
@@ -91,10 +93,11 @@ public ScriptOptions CreateScriptOptions()
9193
_externalReferences.Clear();
9294

9395
return ScriptOptions.Default
94-
.WithMetadataResolver(this)
95-
.WithReferences(GetCompilationReferences())
96-
.WithImports(DefaultNamespaceImports)
97-
.WithSourceResolver(new SourceFileResolver(ImmutableArray<string>.Empty, _scriptFileDirectory));
96+
.WithFilePath(Path.GetFileName(_scriptFilePath))
97+
.WithMetadataResolver(this)
98+
.WithReferences(GetCompilationReferences())
99+
.WithImports(DefaultNamespaceImports)
100+
.WithSourceResolver(new SourceFileResolver(ImmutableArray<string>.Empty, _scriptFileDirectory));
98101
}
99102

100103
/// <summary>

src/WebJobs.Script/Description/FunctionInvokerBase.cs

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -168,6 +168,32 @@ internal void TraceCompilationDiagnostics(ImmutableArray<Diagnostic> diagnostics
168168
{
169169
traceWriter.Trace(diagnostic.ToString(), diagnostic.Severity.ToTraceLevel(), properties);
170170
}
171+
172+
if (Host.InDebugMode && Host.IsPrimary)
173+
{
174+
Host.EventManager.Publish(new StructuredLogEntryEvent(() =>
175+
{
176+
var logEntry = new StructuredLogEntry("codediagnostic");
177+
logEntry.AddProperty("functionName", Metadata.Name);
178+
logEntry.AddProperty("diagnostics", diagnostics.Select(d =>
179+
{
180+
FileLinePositionSpan span = d.Location.GetMappedLineSpan();
181+
return new
182+
{
183+
code = d.Id,
184+
message = d.GetMessage(),
185+
source = Path.GetFileName(d.Location.SourceTree?.FilePath ?? span.Path ?? string.Empty),
186+
severity = d.Severity,
187+
startLineNumber = span.StartLinePosition.Line + 1,
188+
startColumn = span.StartLinePosition.Character + 1,
189+
endLine = span.EndLinePosition.Line + 1,
190+
endColumn = span.EndLinePosition.Character + 1,
191+
};
192+
}));
193+
194+
return logEntry;
195+
}));
196+
}
171197
}
172198

173199
protected virtual void Dispose(bool disposing)

src/WebJobs.Script/Diagnostics/FileTraceWriter.cs

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@ public class FileTraceWriter : TraceWriter, IDisposable
2323
internal const int MaxLogLinesPerFlushInterval = 250;
2424
private readonly string _logFilePath;
2525
private readonly string _instanceId;
26+
private readonly Func<string, string> _messageFormatter;
2627

2728
private readonly DirectoryInfo _logDirectory;
2829
private static object _syncLock = new object();
@@ -32,10 +33,11 @@ public class FileTraceWriter : TraceWriter, IDisposable
3233
private Timer _flushTimer;
3334
private ConcurrentQueue<string> _logBuffer = new ConcurrentQueue<string>();
3435

35-
public FileTraceWriter(string logFilePath, TraceLevel level) : base(level)
36+
public FileTraceWriter(string logFilePath, TraceLevel level, Func<string, string> messageFormatter = null) : base(level)
3637
{
3738
_logFilePath = logFilePath;
3839
_instanceId = GetInstanceId();
40+
_messageFormatter = messageFormatter ?? FormatMessage;
3941

4042
_logDirectory = new DirectoryInfo(logFilePath);
4143
if (!_logDirectory.Exists)
@@ -209,10 +211,14 @@ protected virtual void AppendLine(string line)
209211

210212
// add the line to the current buffer batch, which is flushed
211213
// on a timer
212-
line = string.Format(CultureInfo.InvariantCulture, "{0} {1}", DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ss.fff", CultureInfo.InvariantCulture), line.Trim());
214+
line = _messageFormatter(line);
215+
213216
_logBuffer.Enqueue(line);
214217
}
215218

219+
private string FormatMessage(string message)
220+
=> string.Format(CultureInfo.InvariantCulture, "{0} {1}", DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ss.fff", CultureInfo.InvariantCulture), message.Trim());
221+
216222
private void OnFlushLogs(object sender, ElapsedEventArgs e)
217223
{
218224
Flush();
Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,56 @@
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.Diagnostics;
7+
using System.IO;
8+
using System.Linq;
9+
using System.Reactive.Linq;
10+
using System.Text;
11+
using System.Threading.Tasks;
12+
using Microsoft.Azure.WebJobs.Script.Eventing;
13+
14+
namespace Microsoft.Azure.WebJobs.Script.Diagnostics
15+
{
16+
public sealed class StructuredLogWriter : IDisposable
17+
{
18+
private readonly IDisposable _subscription;
19+
private readonly FileTraceWriter _traceWriter;
20+
private bool _disposedValue = false;
21+
22+
public StructuredLogWriter(IScriptEventManager eventManager, string baseLogPath)
23+
{
24+
string logPath = Path.Combine(baseLogPath, "structured");
25+
_traceWriter = new FileTraceWriter(logPath, TraceLevel.Verbose, s => s);
26+
27+
_subscription = eventManager.OfType<StructuredLogEntryEvent>()
28+
.Subscribe(OnLogEntry);
29+
}
30+
31+
private void OnLogEntry(StructuredLogEntryEvent logEvent)
32+
{
33+
string message = logEvent.LogEntry.ToJsonLineString();
34+
_traceWriter.Trace(message, TraceLevel.Verbose, null);
35+
}
36+
37+
private void Dispose(bool disposing)
38+
{
39+
if (!_disposedValue)
40+
{
41+
if (disposing)
42+
{
43+
_subscription?.Dispose();
44+
_traceWriter?.Dispose();
45+
}
46+
47+
_disposedValue = true;
48+
}
49+
}
50+
51+
public void Dispose()
52+
{
53+
Dispose(true);
54+
}
55+
}
56+
}
Lines changed: 74 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,74 @@
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.IO;
7+
using System.Linq;
8+
using Newtonsoft.Json;
9+
using Newtonsoft.Json.Linq;
10+
11+
namespace Microsoft.Azure.WebJobs.Script.Eventing
12+
{
13+
public sealed class StructuredLogEntry
14+
{
15+
private readonly Dictionary<string, object> _properties = new Dictionary<string, object>();
16+
17+
public StructuredLogEntry(string name)
18+
: this(Guid.NewGuid(), name)
19+
{
20+
}
21+
22+
public StructuredLogEntry(Guid id, string name)
23+
{
24+
Id = id;
25+
Name = name;
26+
_properties = new Dictionary<string, object>();
27+
}
28+
29+
/// <summary>
30+
/// Gets the event ID. This uniquely identifies this <see cref="StructuredLogEntry"/> instance.
31+
/// </summary
32+
public Guid Id { get; }
33+
34+
/// <summary>
35+
/// Gets the event name. This identifies the type of event represented by the <see cref="StructuredLogEntry"/> instance.
36+
/// </summary>
37+
public string Name { get; }
38+
39+
/// <summary>
40+
/// Adds a log entry property.
41+
/// </summary>
42+
/// <param name="name">The property name.</param>
43+
/// <param name="value">The property value.</param>
44+
public void AddProperty(string name, object value)
45+
{
46+
if (string.Equals(nameof(Name), name, StringComparison.OrdinalIgnoreCase) ||
47+
string.Equals(nameof(Id), name, StringComparison.OrdinalIgnoreCase))
48+
{
49+
throw new ArgumentException($"{name} is an invalid property name.", nameof(name));
50+
}
51+
52+
_properties.Add(name, value);
53+
}
54+
55+
/// <summary>
56+
/// Returns a JSON string representation of this object in a single line.
57+
/// </summary>
58+
/// <returns>A JSON string representation of this object in a single line.</returns>
59+
public string ToJsonLineString()
60+
{
61+
var resultObject = new JObject
62+
{
63+
["name"] = Name,
64+
["id"] = Id
65+
};
66+
foreach (var item in _properties)
67+
{
68+
resultObject.Add(item.Key, JToken.FromObject(item.Value));
69+
}
70+
71+
return resultObject.ToString(Formatting.None);
72+
}
73+
}
74+
}
Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,36 @@
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.Threading;
6+
7+
namespace Microsoft.Azure.WebJobs.Script.Eventing
8+
{
9+
public sealed class StructuredLogEntryEvent : ScriptEvent
10+
{
11+
private readonly Lazy<StructuredLogEntry> _logEntry;
12+
13+
public StructuredLogEntryEvent(StructuredLogEntry logEntry)
14+
: this(logEntry, string.Empty)
15+
{
16+
}
17+
18+
public StructuredLogEntryEvent(StructuredLogEntry logEntry, string source)
19+
: this(() => logEntry, source)
20+
{
21+
}
22+
23+
public StructuredLogEntryEvent(Func<StructuredLogEntry> logEntryFactory)
24+
: this(logEntryFactory, string.Empty)
25+
{
26+
}
27+
28+
public StructuredLogEntryEvent(Func<StructuredLogEntry> logEntryFactory, string source)
29+
: base(nameof(StructuredLogEntryEvent), source)
30+
{
31+
_logEntry = new Lazy<StructuredLogEntry>(logEntryFactory, LazyThreadSafetyMode.ExecutionAndPublication);
32+
}
33+
34+
public StructuredLogEntry LogEntry => _logEntry.Value;
35+
}
36+
}

src/WebJobs.Script/Description/DotNet/DiagnosticExtensions.cs renamed to src/WebJobs.Script/Extensions/DiagnosticExtensions.cs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,9 +4,10 @@
44
using System;
55
using System.Collections.Generic;
66
using System.Reflection;
7+
using Microsoft.Azure.WebJobs.Script.Eventing;
78
using Microsoft.CodeAnalysis;
89

9-
namespace Microsoft.Azure.WebJobs.Script.Description.DotNet.CSharp.Analyzers
10+
namespace Microsoft.Azure.WebJobs.Script.Description
1011
{
1112
internal static class DiagnosticExtensions
1213
{

src/WebJobs.Script/GlobalSuppressions.cs

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -207,3 +207,8 @@
207207
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly", MessageId = "Sku", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptConstants.#DynamicSkuConnectionLimit")]
208208
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Reliability", "CA2001:AvoidCallingProblematicMethods", MessageId = "System.Reflection.Assembly.LoadFrom", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptHost.#AddDirectTypes(System.Collections.Generic.List`1<System.Type>,System.Collections.ObjectModel.Collection`1<Microsoft.Azure.WebJobs.Script.Description.FunctionDescriptor>)")]
209209
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Reliability", "CA2001:AvoidCallingProblematicMethods", MessageId = "System.Reflection.Assembly.LoadFrom", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.ScriptHost.#LoadCustomExtensions(System.String)")]
210+
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Reliability", "CA2000:Dispose objects before losing scope", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.DefaultLoggerFactoryBuilder.#AddLoggerProviders(Microsoft.Extensions.Logging.ILoggerFactory,Microsoft.Azure.WebJobs.Script.ScriptHostConfiguration,Microsoft.Azure.WebJobs.Script.Config.ScriptSettingsManager)")]
211+
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Usage", "CA2202:Do not dispose objects multiple times", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.Eventing.StructuredLogging.StructuredLogEntry.#ToJson()")]
212+
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Usage", "CA2202:Do not dispose objects multiple times", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.Eventing.StructuredLogging.StructuredLogEntry.#ToJson()")]
213+
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Usage", "CA2213:DisposableFieldsShouldBeDisposed", MessageId = "_traceWriter", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.Diagnostics.StructuredLogWriter.#Dispose(System.Boolean)")]
214+
[assembly: System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Reliability", "CA2000:Dispose objects before losing scope", Scope = "member", Target = "Microsoft.Azure.WebJobs.Script.FileTraceWriter.#.ctor(System.String,System.Diagnostics.TraceLevel,System.Func`2<System.String,System.String>)")]

0 commit comments

Comments
 (0)