/// <summary>
/// Add correlation data
/// </summary>
/// <param name="key">key</param>
/// <param name="value">value</param>
/// <param name="data">existing correlation data</param>
public void CorrelationAdd(string key, string value, CorrelationData data)
{
if (data != null)
{
data.AddData(key, value);
}
}
/// <summary>
/// Add data to the current correlation
/// </summary>
/// <remarks>If there is no current correlation, starts a new correlation</remarks>
/// <param name="key">key (name) of the correlation</param>
/// <param name="value">value of the added correlation data</param>
public void CorrelationAdd(string key, string value)
{
Code.ExpectsNotNullOrWhiteSpaceArgument(key, nameof(key), TaggingUtilities.ReserveTag(0x2381771e /* tag_96x24 */));
Code.ExpectsNotNullOrWhiteSpaceArgument(value, nameof(value), TaggingUtilities.ReserveTag(0x2381771f /* tag_96x25 */));
CorrelationData data = CurrentCorrelation;
if (data == null)
{
CorrelationStart(null);
data = CurrentCorrelation;
}
if (data != null)
{
string oldData = data.Data(key);
CorrelationHandler.CorrelationAdd(key, value, data);
EventHandler <CorrelationEventArgs> correlationDataAdded = CorrelationDataAdded;
if (correlationDataAdded != null)
{
correlationDataAdded(this, new CorrelationEventArgs(data, key, oldData));
}
}
}
/// <summary>
/// Start correlation
/// </summary>
/// <param name="data">existing correlation data</param>
/// <returns>correlation data</returns>
public CorrelationData CorrelationStart(CorrelationData data)
{
if (data == null)
{
data = new CorrelationData();
data.VisibleId = Guid.NewGuid();
}
return(data);
}
/// <summary>
/// Create a timed scope
/// </summary>
/// <param name="scopeDefinition">Timed scope definition</param>
/// <param name="initialResult">The default result for the scope</param>
/// <param name="customLogger">Use a custom logger for the timed scope</param>
/// <param name="replayEventConfigurator">Replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <param name="correlationData">Correlation data</param>
/// <param name="machineInformation">Machine Information</param>
/// <returns>Newly created scope</returns>
public static TimedScope Create(TimedScopeDefinition scopeDefinition, CorrelationData correlationData, IMachineInformation machineInformation,
ITimedScopeLogger customLogger, IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager,
TimedScopeResult initialResult = default(TimedScopeResult))
{
return(new TimedScope(scopeDefinition, correlationData, customLogger, replayEventConfigurator, machineInformation, timedScopeStackManager)
{
TimedScopeData = correlationData,
RunningTransaction = TransactionMonitor.RunningTransaction(correlationData),
Result = initialResult,
});
}
/// <summary>
/// Creates a scope (and starts by default)
/// </summary>
/// <param name="correlationData">Correlation Data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="initialResult">Initial result to use</param>
/// <param name="startScope">Should the scope be automatically started (for use in e.g. 'using' statement)</param>
/// <param name="customLogger">Optional custom timed scope logger</param>
/// <param name="replayEventConfigurator">Optional replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <returns>A timed scope</returns>
public TimedScope Create(CorrelationData correlationData, IMachineInformation machineInformation, ITimedScopeLogger customLogger, IReplayEventConfigurator replayEventConfigurator,
ITimedScopeStackManager timedScopeStackManager, TimedScopeResult initialResult = default(TimedScopeResult), bool startScope = true)
{
TimedScope scope = TimedScope.Create(this, correlationData, machineInformation, customLogger, replayEventConfigurator, timedScopeStackManager, initialResult);
if (startScope)
{
scope.Start();
}
return(scope);
}
/// <summary>
/// Clone the correlation
/// </summary>
/// <param name="existingCorrelation">existing correlation</param>
/// <returns>cloned correlation, null if existing correlation is null</returns>
/// <remarks>Added as a extension method instead of a method on the
/// object to allow for cloning of the data when it is null, i.e.
/// CorrelationData data = null; data.Clone(); will not throw exception.</remarks>
public static CorrelationData Clone(this CorrelationData existingCorrelation)
{
if (existingCorrelation == null)
{
return(null);
}
CorrelationData newCorrelation = new CorrelationData(existingCorrelation.CachedUlsEventsReplayed);
newCorrelation.ShouldLogDirectly = existingCorrelation.ShouldLogDirectly;
newCorrelation.ShouldReplayUls = existingCorrelation.ShouldReplayUls;
newCorrelation.VisibleId = existingCorrelation.VisibleId;
newCorrelation.CallDepth = existingCorrelation.CallDepth;
newCorrelation.UserHash = existingCorrelation.UserHash;
newCorrelation.EventSequenceNumber = existingCorrelation.EventSequenceNumber;
newCorrelation.IsFallbackCall = existingCorrelation.IsFallbackCall;
newCorrelation.TransactionContextId = existingCorrelation.TransactionContextId;
newCorrelation.TransactionId = existingCorrelation.TransactionId;
newCorrelation.TransactionStep = existingCorrelation.TransactionStep;
if (existingCorrelation.HasData)
{
bool copiedSuccessfully = SpinWait.SpinUntil(() =>
{
bool success = false;
try
{
foreach (object key in existingCorrelation.Keys)
{
string keystring = (string)key;
newCorrelation.AddData(keystring, existingCorrelation.Data(keystring));
}
success = true;
}
catch (InvalidOperationException)
{
}
return(success);
}, 10);
if (!copiedSuccessfully)
{
// Add a marker to the correlation data indicating it is not complete
newCorrelation.AddData("Error", "Failed to clone correlation data.");
}
}
return(newCorrelation);
}
/// <summary>
/// Constructor
/// </summary>
/// <param name="scopeDefinition">Timed scope definition</param>
/// <param name="scopeLogger">Scope metrics logger</param>
/// <param name="replayEventConfigurator">Replay event configurator</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <param name="correlationData">Correlation data</param>
private TimedScope(TimedScopeDefinition scopeDefinition, CorrelationData correlationData, ITimedScopeLogger scopeLogger, IReplayEventConfigurator replayEventConfigurator,
IMachineInformation machineInformation, ITimedScopeStackManager timedScopeStackManager)
{
Code.ExpectsArgument(scopeDefinition, nameof(scopeDefinition), TaggingUtilities.ReserveTag(0x238174da /* tag_96xt0 */));
Code.ExpectsArgument(scopeLogger, nameof(scopeLogger), TaggingUtilities.ReserveTag(0x238174db /* tag_96xt1 */));
Code.ExpectsArgument(replayEventConfigurator, nameof(replayEventConfigurator), TaggingUtilities.ReserveTag(0x238174dc /* tag_96xt2 */));
Code.ExpectsArgument(timedScopeStackManager, nameof(timedScopeStackManager), TaggingUtilities.ReserveTag(0x23817062 /* tag_96xb8 */));
ScopeDefinition = scopeDefinition;
ScopeLogger = scopeLogger;
ReplayEventConfigurator = replayEventConfigurator;
CorrelationData = correlationData;
MachineInformation = machineInformation;
TimedScopeStackManager = timedScopeStackManager;
}
/// <summary>
/// Logs the scope end to ULS
/// </summary>
private void LogEnd(IMachineInformation machineInformation)
{
if (!IsSuccessful.HasValue)
{
ULSLogging.LogTraceTag(0x238174e3 /* tag_96xt9 */, Categories.TimingGeneral, Levels.Warning,
"Result not set for scope {0}. Considered as SystemError", Name);
Result = TimedScopeResult.SystemError;
FailureDescription = InternalFailureDescription.UnknownResultAsSystemError;
}
CorrelationData scopeData = ConstructCorrelationDataEntries(machineInformation);
ScopeLogger.LogScopeEnd(this, scopeData);
ReplayEventConfigurator.ConfigureReplayEventsOnScopeEnd(this);
}
/// <summary>
/// Creates a new TransactionData object from the current CorrelationData object.
/// </summary>
/// <param name="correlationData">The CorrelationData object to copy when creating the TransactionData object.</param>
/// <returns>A new TransactionData copy of the supplied CorrelationData or null if the current CorrelationData is null.</returns>
public static TransactionData ToTransactionData(this CorrelationData correlationData)
{
if (correlationData == null)
{
return(null);
}
return(new TransactionData()
{
CallDepth = correlationData.CallDepth,
CorrelationId = correlationData.VisibleId,
EventSequenceNumber = correlationData.EventSequenceNumber,
TransactionContextId = correlationData.TransactionContextId,
TransactionId = correlationData.TransactionId,
TransactionStep = correlationData.TransactionStep,
UserHash = correlationData.UserHash,
IsFallbackCall = correlationData.IsFallbackCall
});
}
/// <summary>
/// End the correlation
/// </summary>
/// <param name="id">Id of the thread</param>
/// <param name="invokeEventHandler">Should we invoke the correlation ended event handler</param>
public void CorrelationEnd(int?id = null, bool invokeEventHandler = true)
{
CorrelationData correlationData = GetCorrelationData(id);
if (correlationData != null)
{
CurrentCorrelation = correlationData.ParentCorrelation;
CorrelationHandler.CorrelationEnd(correlationData);
if (invokeEventHandler)
{
EventHandler <CorrelationEventArgs> correlationEnded = CorrelationEnded;
if (correlationEnded != null)
{
correlationEnded(this, new CorrelationEventArgs(correlationData));
}
}
}
}
/// <summary>
/// Start a correlation
/// </summary>
/// <param name="data">correlation to set on the thread, null for default (new) correlation</param>
public void CorrelationStart(CorrelationData data)
{
data = CorrelationHandler.CorrelationStart(data);
if (data != null)
{
data.ParentCorrelation = CurrentCorrelation;
if (data.ParentCorrelation == null)
{
data.ShouldLogDirectly = ShouldLogDirectly;
}
CurrentCorrelation = data;
// Note: Creating a copy of the event handler to avoid multi-threaded race conditions
// Not creating extension methods to avoid unnecessary creating of arguments if not set
EventHandler <CorrelationEventArgs> correlationStarted = CorrelationStarted;
if (correlationStarted != null)
{
correlationStarted(this, new CorrelationEventArgs(data));
}
}
}
/// <summary>
/// Constructs the timed scope correlation data
/// </summary>
/// <returns>Correlation data</returns>
private CorrelationData ConstructCorrelationDataEntries(IMachineInformation machineInformation)
{
CorrelationData correlationData = TimedScopeData;
CorrelationData scopeData = TimedScopeData.Clone();
scopeData.AddData(TimedScopeDataKeys.InternalOnly.ScopeName, Name);
scopeData.AddData(TimedScopeDataKeys.InternalOnly.InstanceId, InstanceId.ToString());
scopeData.AddData(TimedScopeDataKeys.InternalOnly.IsSuccessful, IsSuccessful.HasValue ? IsSuccessful.Value.ToString() : bool.FalseString);
scopeData.AddData(TimedScopeDataKeys.InternalOnly.IsRoot, IsRoot.ToString());
scopeData.AddData(TimedScopeDataKeys.InternalOnly.ScopeResult, Result.ToString());
bool isFailed = !IsSuccessful ?? false;
if (isFailed && FailureDescription != null)
{
scopeData.AddData(TimedScopeDataKeys.InternalOnly.FailureDescription, FailureDescription.ToString());
}
scopeData.AddData(TimedScopeDataKeys.InternalOnly.Duration, DurationInMilliseconds.ToString(CultureInfo.InvariantCulture));
long sequenceNumber = correlationData == null ? 0 : correlationData.NextEventSequenceNumber();
scopeData.AddData(TimedScopeDataKeys.InternalOnly.SequenceNumber, sequenceNumber.ToString(CultureInfo.InvariantCulture));
scopeData.AddData(TimedScopeDataKeys.InternalOnly.CallDepth, correlationData == null ? "0" : correlationData.CallDepth.ToString(CultureInfo.InvariantCulture));
IMachineInformation machineInfo = machineInformation;
if (machineInfo != null)
{
scopeData.AddData(TimedScopeDataKeys.InternalOnly.MachineId, machineInfo.MachineId);
scopeData.AddData(TimedScopeDataKeys.InternalOnly.MachineCluster, machineInfo.MachineCluster);
scopeData.AddData(TimedScopeDataKeys.InternalOnly.MachineRole, machineInfo.MachineRole);
scopeData.AddData(TimedScopeDataKeys.InternalOnly.AgentName, machineInfo.AgentName);
}
// if the user hash has been set, add it to the scope data
if (!string.IsNullOrWhiteSpace(m_userHashOverride))
{
ULSLogging.LogTraceTag(0x23817500 /* tag_96xua */, Categories.TimingGeneral, Levels.Verbose,
"Overriding user hash metadata in the Timed Scope '{0}' with value '{1}'", Name, m_userHashOverride);
scopeData.AddData(TimedScopeDataKeys.InternalOnly.UserHash, m_userHashOverride);
}
else if (correlationData != null && !string.IsNullOrWhiteSpace(correlationData.UserHash))
{
scopeData.AddData(TimedScopeDataKeys.InternalOnly.UserHash, correlationData.UserHash);
}
// capture performance metrics
if (PerfDiagnostics != null && PerfDiagnostics.LastStatus)
{
scopeData.AddData(TimedScopeDataKeys.InternalOnly.CpuCycles,
PerfDiagnostics.CyclesUsed.ToString(CultureInfo.InvariantCulture));
scopeData.AddData(TimedScopeDataKeys.InternalOnly.UserModeDuration,
PerfDiagnostics.UserModeMilliseconds.ToString(CultureInfo.InvariantCulture));
scopeData.AddData(TimedScopeDataKeys.InternalOnly.KernelModeDuration,
PerfDiagnostics.KernelModeMilliseconds.ToString(CultureInfo.InvariantCulture));
scopeData.AddData(TimedScopeDataKeys.InternalOnly.HttpRequestCount,
PerfDiagnostics.HttpRequestCount.ToString(CultureInfo.InvariantCulture));
scopeData.AddData(TimedScopeDataKeys.InternalOnly.ServiceCallCount,
PerfDiagnostics.ServiceCallCount.ToString(CultureInfo.InvariantCulture));
}
return(scopeData);
}
/// <summary>
/// Starts a scope
/// </summary>
/// <param name="correlationData">Correlation Data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="initialResult">Initial result to use</param>
/// <param name="customLogger">Optional custom timed scope logger</param>
/// <param name="replayEventConfigurator">Optional replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <returns>A timed scope</returns>
public TimedScope Start(CorrelationData correlationData, IMachineInformation machineInformation, ITimedScopeLogger customLogger,
IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager, TimedScopeResult initialResult = default(TimedScopeResult))
=> Create(correlationData, machineInformation, customLogger, replayEventConfigurator, timedScopeStackManager, initialResult: initialResult, startScope: true);
/// <summary>
/// Constructor
/// </summary>
/// <param name="data">correlation data</param>
public CorrelationEventArgs(CorrelationData data)
{
Correlation = data;
ChangedKey = null;
OldData = null;
}
/// <summary>
/// Constructor
/// </summary>
/// <param name="data">correlation data</param>
/// <param name="key">changed key</param>
/// <param name="oldData">the previous value of the data</param>
public CorrelationEventArgs(CorrelationData data, string key, string oldData)
{
Correlation = data;
ChangedKey = key;
OldData = oldData;
}
/// <summary>
/// Deprecated - Creates a scope
/// </summary>
/// <remarks>This overload is obsoleted. Use the overload with TimedScopeResult for new scopes instead.</remarks>
/// <param name="correlationData">Correlation data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="initialResult">Initial result to use</param>
/// <param name="startScope">Should the scope be automatically started (for use in e.g. 'using' statement)</param>
/// <param name="customLogger">Optional custom timed scope logger</param>
/// <param name="replayEventConfigurator">Optional replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <returns>A timed scope</returns>
public TimedScope Create(CorrelationData correlationData, IMachineInformation machineInformation, ITimedScopeLogger customLogger,
IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager, bool?initialResult, bool startScope = true)
=> Create(correlationData, machineInformation, customLogger, replayEventConfigurator, timedScopeStackManager,
TimedScope.ConvertBoolResultToTimedScopeResult(initialResult), startScope);
/// <summary>
/// Deprecated - Start a timed scope
/// </summary>
/// <remarks>Please use TimedScopeDefinition for creating timed scopes</remarks>
/// <param name="correlationData">Correlation Data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="scopeName">The name of the timed scope</param>
/// <param name="description">The description of the timed scope</param>
/// <param name="initialResult">The default result for the scope</param>
/// <param name="customLogger">Use a custom logger for the timed scope</param>
/// <param name="replayEventConfigurator">Replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <returns>Newly created scope</returns>
public static TimedScope Start(CorrelationData correlationData, IMachineInformation machineInformation, string scopeName, string description,
ITimedScopeLogger customLogger, IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager,
TimedScopeResult initialResult = default(TimedScopeResult))
=> new TimedScopeDefinition(scopeName, description).Start(correlationData, machineInformation, customLogger, replayEventConfigurator,
timedScopeStackManager, initialResult);
/// <summary>
/// Deprecated - Create a timed scope
/// </summary>
/// <remarks>Please use TimedScopeDefinition for creating timed scopes</remarks>
/// <param name="correlationData">Correlation data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="scopeName">The name of the timed scope</param>
/// <param name="initialResult">The default result for the scope</param>
/// <param name="customLogger">Use a custom logger for the timed scope</param>
/// <param name="replayEventConfigurator">Replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <returns>newly created scope</returns>
public static TimedScope Create(CorrelationData correlationData, IMachineInformation machineInformation, string scopeName, ITimedScopeLogger customLogger,
IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager, bool?initialResult = null)
=> new TimedScopeDefinition(scopeName).Create(correlationData, machineInformation, customLogger, replayEventConfigurator, timedScopeStackManager,
initialResult: initialResult, startScope: false);
/// <summary>
/// Start the timed scope
/// </summary>
public void Start()
{
if (IsDisposed)
{
ULSLogging.LogTraceTag(0x238174dd /* tag_96xt3 */, Categories.TimingGeneral, Levels.Error,
"Attempting to start scope '{0}' that has already been disposed.", Name);
return;
}
if (IsScopeActive)
{
ULSLogging.LogTraceTag(0x238174de /* tag_96xt4 */, Categories.TimingGeneral, Levels.Error,
"Attempting to start scope '{0}' that has already been started.", Name);
return;
}
string metaDataCopy = MetaData;
string subTypeCopy = SubType;
CorrelationData currentCorrelation = CorrelationData;
TimedScopeData = currentCorrelation.Clone() ?? new CorrelationData();
RunningTransaction = TransactionMonitor.RunningTransaction(TimedScopeData);
if (!string.IsNullOrWhiteSpace(metaDataCopy) && string.IsNullOrWhiteSpace(MetaData))
{
MetaData = metaDataCopy;
}
if (!string.IsNullOrWhiteSpace(subTypeCopy) && string.IsNullOrWhiteSpace(SubType))
{
SubType = subTypeCopy;
}
// differentiate scope name when running under a test transaction
if (IsTransaction)
{
NameSuffix = string.Concat(NameSuffix, "::Trx", RunningTransaction.ToString(CultureInfo.InvariantCulture));
}
// differentiate special scopes
if (TimedScopeData.IsFallbackCall)
{
NameSuffix = string.Concat(NameSuffix, "::Fallback");
}
// differentiate scope name for inner (proxied) calls
if (TimedScopeData.CallDepth > 0)
{
NameSuffix = string.Concat(NameSuffix, "::Depth", TimedScopeData.CallDepth.ToString(CultureInfo.InvariantCulture));
if (currentCorrelation != null)
{
// reset call depth so any inner scopes are reported as layer 0 again
currentCorrelation.CallDepth = 0;
}
}
Parent = TimedScopeStackManager.Scopes?.Peek();
IsRoot = Parent == null && TimedScopeData.CallDepth == 0;
StartTick = Stopwatch.GetTimestamp();
IsScopeActive = true;
ScopeLogger.LogScopeStart(this);
PerfDiagnostics = new PerfDiagnostics(Parent != null ? Parent.PerfDiagnostics : null);
PerfDiagnostics.Start();
}
/// <summary>
/// Deprecated - Create a timed scope
/// </summary>
/// <remarks>Please use TimedScopeDefinition for creating timed scopes</remarks>
/// <param name="correlationData">Correlation data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="scopeName">The name of the timed scope</param>
/// <param name="description">The description of the timed scope</param>
/// <param name="customLogger">Use a custom logger for the timed scope</param>
/// <param name="replayEventConfigurator">Replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <param name="initialResult">The default result for the scope</param>
/// <returns>Newly created scope</returns>
public static TimedScope Create(CorrelationData correlationData, IMachineInformation machineInformation, string scopeName, string description,
ITimedScopeLogger customLogger, IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager, bool?initialResult)
=> new TimedScopeDefinition(scopeName, description).Create(correlationData, machineInformation, customLogger, replayEventConfigurator,
timedScopeStackManager, initialResult: ConvertBoolResultToTimedScopeResult(initialResult), startScope: false);
/// <summary>
/// End correlation
/// </summary>
/// <param name="data">correlation data</param>
public void CorrelationEnd(CorrelationData data)
{
}
/// <summary>
/// Deprecated - Start a timed scope
/// </summary>
/// <remarks>Please use TimedScopeDefinition for creating timed scopes</remarks>
/// <param name="correlationData">Correlation data</param>
/// <param name="machineInformation">Machine Information</param>
/// <param name="scopeName">The name of the timed scope</param>
/// <param name="customLogger">Use a custom logger for the timed scope</param>
/// <param name="replayEventConfigurator">Replay event configurator</param>
/// <param name="timedScopeStackManager">Timed scope stack manager</param>
/// <param name="initialResult">The default result for the scope</param>
/// <returns>Newly created scope</returns>
public static TimedScope Start(CorrelationData correlationData, IMachineInformation machineInformation, string scopeName, ITimedScopeLogger customLogger,
IReplayEventConfigurator replayEventConfigurator, ITimedScopeStackManager timedScopeStackManager, bool?initialResult)
=> new TimedScopeDefinition(scopeName).Start(correlationData, machineInformation, customLogger, replayEventConfigurator,
timedScopeStackManager, ConvertBoolResultToTimedScopeResult(initialResult));
