|
This PR overhauls how logging is accomplished in the System.Net libraries.
There are a few problems with the existing solution:
1. In the original sources, logging was split across a GlobalLog class and a Logging class. Global-related tracing went to GlobalLog, and library-specific tracing went to Logging. When the sources were moved to corefx, this evolved into multiple EventSource-based types, most of which were in Common and were then src-included into each System.Net assembly. This has a significant problem, though, which is that the name/Guid identity of an EventSource can only exist once in a process, and subsequent EventSource instances with the same identity fail. This means that whichever assembly ends up logging something first wins, and all other tracing from other System.Net assemblies ends up being lost.
2. The split also may have made sense when all components shared the same GlobalLog, but now that GlobalLog is included as a unique EventSource instance in each assembly, it's no longer global. This means that we're not only loading multiple EventSources unnecessarily (each has its own costs), but we're also duplicating logging, as some logging is done to one or the other, but some logging is done to both.
3. Due to sharing the Logging class, which evolved into an EventSource-based type, many logging calls had to include which component they came from as an enum value, leading to bloating at the call sites.
4. Additionally, many logging operations included the name of the method in which the calling was being done, which meant both longer call sites as well as stale values as members got renamed over time.
5. Call sites ended up getting fairly long due to lots of string concatenation operations and other manipulations in the logging call. This also then led to most call sites needing to be guarded behind checks for IsEnabled, leading to lots of code at every call site and obscuring the actual information being traced.
6. An additional requirement that got added with the move to corefx was that certain failure conditions should both Debug.Fail and do tracing, leading to some tracing operations taking upwards of 10 lines of code.
All of these issues are addressed by this PR.
- Each System.Net assembly that needs to log now loads a single NetEventSource type for doing logging, each with its own identity.
- That implementation is split across a common, partial NetEventSource.Common.cs file used by all such assemblies, and then a per-assembly partial NetEventSource.AssemblyName.cs file used by the individual assembly. The former file contains most of the logging implementation. The latter files typically contain just the partial class declaration along with the [EventSource] attribute that gives that assembly's NetEventSource its unique identity / name.
- The logging operations in NetEventSource.Common.cs use a variety of relatively-recent language enhancements to improve the logging. Each operation uses a [CallerMemberName] so that the call sites don't need to specify the caller. FormattableString is used so that call sites can use string interpolation while still providing the logging implementation the flexibility to format the individual components in a desired fashion (e.g. IntPtrs are formatted as hex, SafeHandles are rendered in a way that includes their name+hashcode+handle, etc.), along with a mechanism that allows individual libraries to add additional formatting rules. Each operation allows the this reference (or another this-like context object) to be passed in, to simply identify the source of the call (in concert with the caller member name). A debug-only mechanism is included in the tracing to help find potential perf issues due to misuse of the logger. Etc.
- A Fail logging operation is included that both traces and does a Debug.Fail.
With these changes, most call sites are greatly simplified. Some examples:
Before:
```C#
if (GlobalLog.IsEnabled)
{
GlobalLog.AssertFormat("ContextAwareResult#{0}::ContextCopy|Called on completed result.", LoggingHash.HashString(this));
}
Debug.Fail("ContextAwareResult#" + LoggingHash.HashString(this) + "::ContextCopy |Called on completed result.");
```
After:
```C#
NetEventSource.Fail(this, "Called on completed result.");
```
Before:
```C#
if (NetEventSource.Log.IsEnabled()) NetEventSource.Enter(NetEventSource.ComponentType.Http, this, ".ctor", handler);
```
After:
```C#
NetEventSource.Enter(this, handler);
```
Etc.
In addition to fixing up all of the event sources, I of course also fixed up all usage in order to clean up the call sites. However, this was a rather mechanical change: I did not remove existing logging (other than duplication) nor did I add new logging. At some point, we should review the actual logging being done to determine what's missing and what's not needed. I also did not revise the additional existing events on the sockets and security event sources, but we may want to remove those (or some of those) in favor of just using the shared events.
|
