Skip to content

Commit

Permalink
Add tracing for Resolving/AssemblyResolve event handler invocation (d…
Browse files Browse the repository at this point in the history
  • Loading branch information
elinor-fung authored Nov 12, 2019
1 parent 51e62d2 commit 3857ce6
Show file tree
Hide file tree
Showing 11 changed files with 683 additions and 54 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,12 @@ public partial class AssemblyLoadContext
[MethodImpl(MethodImplOptions.InternalCall)]
internal static extern bool IsTracingEnabled();

[DllImport(RuntimeHelpers.QCall, CharSet = CharSet.Unicode)]
internal static extern bool TraceResolvingHandlerInvoked(string assemblyName, string handlerName, string? alcName, string? resultAssemblyName, string? resultAssemblyPath);

[DllImport(RuntimeHelpers.QCall, CharSet = CharSet.Unicode)]
internal static extern bool TraceAssemblyResolveHandlerInvoked(string assemblyName, string handlerName, string? resultAssemblyName, string? resultAssemblyPath);

private Assembly InternalLoadFromPath(string? assemblyPath, string? nativeImagePath)
{
RuntimeAssembly? loadedAssembly = null;
Expand Down
53 changes: 53 additions & 0 deletions src/coreclr/src/vm/ClrEtwAll.man
Original file line number Diff line number Diff line change
Expand Up @@ -394,6 +394,8 @@
value="32" eventGUID="{BCF2339E-B0A6-452D-966C-33AC9DD82573}"
message="$(string.RuntimePublisher.AssemblyLoaderTaskMessage)">
<opcodes>
<opcode name="AssemblyLoadContextResolvingHandlerInvoked" message="$(string.RuntimePublisher.AssemblyLoadContextResolvingHandlerInvokedOpcodeMessage)" symbol="CLR_ALC_RESOLVING_HANDLER_INVOKED_OPCODE" value="12"/>
<opcode name="AppDomainAssemblyResolveHandlerInvoked" message="$(string.RuntimePublisher.AppDomainAssemblyResolveHandlerInvokedOpcodeMessage)" symbol="CLR_APPDOMAIN_ASSEMBLY_RESOLVE_HANDLER_INVOKED_OPCODE" value="13"/>
</opcodes>
</task>
<!--Next available ID is 33-->
Expand Down Expand Up @@ -1705,6 +1707,42 @@
</UserData>
</template>

<template tid="AssemblyLoadContextResolvingHandlerInvoked">
<data name="ClrInstanceID" inType="win:UInt16" />
<data name="AssemblyName" inType="win:UnicodeString" />
<data name="HandlerName" inType="win:UnicodeString" />
<data name="AssemblyLoadContext" inType="win:UnicodeString" />
<data name="ResultAssemblyName" inType="win:UnicodeString" />
<data name="ResultAssemblyPath" inType="win:UnicodeString" />
<UserData>
<AssemblyLoadContextResolvingHandlerInvoked xmlns="myNs">
<ClrInstanceID> %1 </ClrInstanceID>
<AssemblyName> %2 </AssemblyName>
<HandlerName> %3 </HandlerName>
<AssemblyLoadContext> %4 </AssemblyLoadContext>
<ResultAssemblyName> %5 </ResultAssemblyName>
<ResultAssemblyPath> %6 </ResultAssemblyPath>
</AssemblyLoadContextResolvingHandlerInvoked>
</UserData>
</template>

<template tid="AppDomainAssemblyResolveHandlerInvoked">
<data name="ClrInstanceID" inType="win:UInt16" />
<data name="AssemblyName" inType="win:UnicodeString" />
<data name="HandlerName" inType="win:UnicodeString" />
<data name="ResultAssemblyName" inType="win:UnicodeString" />
<data name="ResultAssemblyPath" inType="win:UnicodeString" />
<UserData>
<AppDomainAssemblyResolveHandlerInvoked xmlns="myNs">
<ClrInstanceID> %1 </ClrInstanceID>
<AssemblyName> %2 </AssemblyName>
<HandlerName> %3 </HandlerName>
<ResultAssemblyName> %4 </ResultAssemblyName>
<ResultAssemblyPath> %5 </ResultAssemblyPath>
</AppDomainAssemblyResolveHandlerInvoked>
</UserData>
</template>

<template tid="MethodLoadUnload">
<data name="MethodID" inType="win:UInt64" outType="win:HexInt64" />
<data name="ModuleID" inType="win:UInt64" outType="win:HexInt64" />
Expand Down Expand Up @@ -3502,6 +3540,16 @@
task="AssemblyLoader"
symbol="AssemblyLoadStop" message="$(string.RuntimePublisher.AssemblyLoadStopEventMessage)"/>

<event value="293" version="0" level="win:Informational" template="AssemblyLoadContextResolvingHandlerInvoked"
keywords ="AssemblyLoaderKeyword" opcode="AssemblyLoadContextResolvingHandlerInvoked"
task="AssemblyLoader"
symbol="AssemblyLoadContextResolvingHandlerInvoked" message="$(string.RuntimePublisher.AssemblyLoadContextResolvingHandlerInvokedEventMessage)"/>

<event value="294" version="0" level="win:Informational" template="AppDomainAssemblyResolveHandlerInvoked"
keywords ="AssemblyLoaderKeyword" opcode="AppDomainAssemblyResolveHandlerInvoked"
task="AssemblyLoader"
symbol="AppDomainAssemblyResolveHandlerInvoked" message="$(string.RuntimePublisher.AppDomainAssemblyResolveHandlerInvokedEventMessage)"/>

</events>
</provider>

Expand Down Expand Up @@ -6699,6 +6747,8 @@
<string id="RuntimePublisher.AppDomainUnload_V1EventMessage" value="AppDomainID=%1;%nAppDomainFlags=%2;%nAppDomainName=%3;%nAppDomainIndex=%4;%nClrInstanceID=%5" />
<string id="RuntimePublisher.AssemblyLoadStartEventMessage" value="ClrInstanceID=%1;%nAssemblyName=%2;%nAssemblyPath=%3;%nRequestingAssembly=%4;%nAssemblyLoadContext=%5;%nRequestingAssemblyLoadContext=%6" />
<string id="RuntimePublisher.AssemblyLoadStopEventMessage" value="ClrInstanceID=%1;%nAssemblyName=%2;%nAssemblyPath=%3;%nRequestingAssembly=%4;%nAssemblyLoadContext=%5;%nRequestingAssemblyLoadContext=%6;%nSuccess=%7;%nResultAssemblyName=%8;%nResultAssemblyPath=%9;%nCached=%10" />
<string id="RuntimePublisher.AssemblyLoadContextResolvingHandlerInvokedEventMessage" value="ClrInstanceID=%1;%nAssemblyName=%2;%nHandlerName=%3;%nAssemblyLoadContext=%4;%nResultAssemblyName=%5;%nResultAssemblyPath=%6" />
<string id="RuntimePublisher.AppDomainAssemblyResolveHandlerInvokedEventMessage" value="ClrInstanceID=%1;%nAssemblyName=%2;%nHandlerName=%3;%nResultAssemblyName=%4;%nResultAssemblyPath=%5" />
<string id="RuntimePublisher.StackEventMessage" value="ClrInstanceID=%1;%nReserved1=%2;%nReserved2=%3;%nFrameCount=%4;%nStack=%5" />
<string id="RuntimePublisher.AppDomainMemAllocatedEventMessage" value="AppDomainID=%1;%nAllocated=%2;%nClrInstanceID=%3" />
<string id="RuntimePublisher.AppDomainMemSurvivedEventMessage" value="AppDomainID=%1;%nSurvived=%2;%nProcessSurvived=%3;%nClrInstanceID=%4" />
Expand Down Expand Up @@ -7327,6 +7377,9 @@
<string id="RuntimePublisher.TieredCompilationPauseOpcodeMessage" value="Pause" />
<string id="RuntimePublisher.TieredCompilationResumeOpcodeMessage" value="Resume" />

<string id="RuntimePublisher.AssemblyLoadContextResolvingHandlerInvokedOpcodeMessage" value="AssemblyLoadContextResolvingHandlerInvoked" />
<string id="RuntimePublisher.AppDomainAssemblyResolveHandlerInvokedOpcodeMessage" value="AppDomainAssemblyResolveHandlerInvoked" />

<string id="RundownPublisher.MethodDCStartOpcodeMessage" value="DCStart" />
<string id="RundownPublisher.MethodDCEndOpcodeMessage" value="DCStop" />
<string id="RundownPublisher.MethodDCStartVerboseOpcodeMessage" value="DCStartVerbose" />
Expand Down
24 changes: 24 additions & 0 deletions src/coreclr/src/vm/assemblynative.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -1428,3 +1428,27 @@ FCIMPL0(FC_BOOL_RET, AssemblyNative::IsTracingEnabled)
FC_RETURN_BOOL(BinderTracing::IsEnabled());
}
FCIMPLEND

// static
void QCALLTYPE AssemblyNative::TraceResolvingHandlerInvoked(LPCWSTR assemblyName, LPCWSTR handlerName, LPCWSTR alcName, LPCWSTR resultAssemblyName, LPCWSTR resultAssemblyPath)
{
QCALL_CONTRACT;

BEGIN_QCALL;

FireEtwAssemblyLoadContextResolvingHandlerInvoked(GetClrInstanceId(), assemblyName, handlerName, alcName, resultAssemblyName, resultAssemblyPath);

END_QCALL;
}

// static
void QCALLTYPE AssemblyNative::TraceAssemblyResolveHandlerInvoked(LPCWSTR assemblyName, LPCWSTR handlerName, LPCWSTR resultAssemblyName, LPCWSTR resultAssemblyPath)
{
QCALL_CONTRACT;

BEGIN_QCALL;

FireEtwAppDomainAssemblyResolveHandlerInvoked(GetClrInstanceId(), assemblyName, handlerName, resultAssemblyName, resultAssemblyPath);

END_QCALL;
}
2 changes: 2 additions & 0 deletions src/coreclr/src/vm/assemblynative.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -133,6 +133,8 @@ class AssemblyNative
static INT_PTR QCALLTYPE GetLoadContextForAssembly(QCall::AssemblyHandle pAssembly);

static BOOL QCALLTYPE InternalTryGetRawMetadata(QCall::AssemblyHandle assembly, UINT8 **blobRef, INT32 *lengthRef);
static void QCALLTYPE TraceResolvingHandlerInvoked(LPCWSTR assemblyName, LPCWSTR handlerName, LPCWSTR alcName, LPCWSTR resultAssemblyName, LPCWSTR resultAssemblyPath);
static void QCALLTYPE TraceAssemblyResolveHandlerInvoked(LPCWSTR assemblyName, LPCWSTR handlerName, LPCWSTR resultAssemblyName, LPCWSTR resultAssemblyPath);
};

#endif
Expand Down
2 changes: 2 additions & 0 deletions src/coreclr/src/vm/ecalllist.h
Original file line number Diff line number Diff line change
Expand Up @@ -513,6 +513,8 @@ FCFuncStart(gAssemblyLoadContextFuncs)
QCFuncElement("InternalStartProfile", MultiCoreJITNative::InternalStartProfile)
#endif // defined(FEATURE_MULTICOREJIT)
FCFuncElement("IsTracingEnabled", AssemblyNative::IsTracingEnabled)
QCFuncElement("TraceResolvingHandlerInvoked", AssemblyNative::TraceResolvingHandlerInvoked)
QCFuncElement("TraceAssemblyResolveHandlerInvoked", AssemblyNative::TraceAssemblyResolveHandlerInvoked)
FCFuncEnd()

FCFuncStart(gAssemblyNameFuncs)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,8 @@
<PropertyGroup>
<OutputType>Library</OutputType>
<CLRTestKind>BuildOnly</CLRTestKind>
<AssemblyName Condition="'$(AssemblyNameSuffix)'!=''">$(AssemblyName)_$(AssemblyNameSuffix)</AssemblyName>
<CleanFile>$(AssemblyName).FileListAbsolute.txt</CleanFile>
</PropertyGroup>
<ItemGroup>
<Compile Include="AssemblyToLoad.cs" />
Expand Down
166 changes: 134 additions & 32 deletions src/coreclr/tests/src/Loader/binding/tracing/BinderEventListener.cs
Original file line number Diff line number Diff line change
Expand Up @@ -15,22 +15,65 @@ namespace BinderTracingTests
{
internal class BindOperation
{
internal AssemblyName AssemblyName;
internal string AssemblyPath;
internal AssemblyName RequestingAssembly;
internal string AssemblyLoadContext;
internal string RequestingAssemblyLoadContext;

internal bool Success;
internal AssemblyName ResultAssemblyName;
internal string ResultAssemblyPath;
internal bool Cached;

internal Guid ActivityId;
internal Guid ParentActivityId;

internal bool Completed;
internal bool Nested;
public AssemblyName AssemblyName { get; internal set; }
public string AssemblyPath { get; internal set; }
public AssemblyName RequestingAssembly { get; internal set; }
public string AssemblyLoadContext { get; internal set; }
public string RequestingAssemblyLoadContext { get; internal set; }

public bool Success { get; internal set; }
public AssemblyName ResultAssemblyName { get; internal set; }
public string ResultAssemblyPath { get; internal set; }
public bool Cached { get; internal set; }

public Guid ActivityId { get; internal set; }
public Guid ParentActivityId { get; internal set; }

public bool Completed { get; internal set; }
public bool Nested { get; internal set; }

public List<HandlerInvocation> AssemblyLoadContextResolvingHandlers { get; internal set; }
public List<HandlerInvocation> AppDomainAssemblyResolveHandlers { get; internal set; }

public List<BindOperation> NestedBinds { get; internal set; }

public BindOperation()
{
AssemblyLoadContextResolvingHandlers = new List<HandlerInvocation>();
AppDomainAssemblyResolveHandlers = new List<HandlerInvocation>();
NestedBinds = new List<BindOperation>();
}

public override string ToString()
{
var sb = new System.Text.StringBuilder();
sb.Append(AssemblyName);
sb.Append($" - Request: Path={AssemblyPath}, ALC={AssemblyLoadContext}, RequestingAssembly={RequestingAssembly}, RequestingALC={RequestingAssemblyLoadContext}");
sb.Append($" - Result: Success={Success}, Name={ResultAssemblyName}, Path={ResultAssemblyPath}, Cached={Cached}");
return sb.ToString();
}
}

internal class HandlerInvocation
{
public AssemblyName AssemblyName { get; internal set; }
public string HandlerName { get; internal set; }
public string AssemblyLoadContext { get; internal set; }

public AssemblyName ResultAssemblyName { get; internal set; }
public string ResultAssemblyPath { get; internal set; }

public override string ToString()
{
var sb = new System.Text.StringBuilder();
sb.Append($"{HandlerName} - ");
sb.Append($"Request: Name={AssemblyName.FullName}");
if (!string.IsNullOrEmpty(AssemblyLoadContext))
sb.Append($", ALC={AssemblyLoadContext}");

sb.Append($" - Result: Name={ResultAssemblyName?.FullName}, Path={ResultAssemblyPath}");
return sb.ToString();
}
}

internal sealed class BinderEventListener : EventListener
Expand Down Expand Up @@ -80,34 +123,32 @@ protected override void OnEventWritten(EventWrittenEventArgs data)
if (data.EventSource.Name != "Microsoft-Windows-DotNETRuntime")
return;

object GetData(string name) => data.Payload[data.PayloadNames.IndexOf(name)];
string GetDataString(string name) => GetData(name).ToString();
object GetData(string name)
{
int index = data.PayloadNames.IndexOf(name);
return index >= 0 ? data.Payload[index] : null;
};
string GetDataString(string name) => GetData(name) as string;

switch (data.EventName)
{
case "AssemblyLoadStart":
{
BindOperation bindOperation = ParseAssemblyLoadStartEvent(data, GetDataString);
lock (eventsLock)
{
Assert.IsTrue(!bindOperations.ContainsKey(data.ActivityId), "AssemblyLoadStart should not exist for same activity ID ");
var bindOperation = new BindOperation()
{
AssemblyName = new AssemblyName(GetDataString("AssemblyName")),
AssemblyPath = GetDataString("AssemblyPath"),
AssemblyLoadContext = GetDataString("AssemblyLoadContext"),
RequestingAssemblyLoadContext = GetDataString("RequestingAssemblyLoadContext"),
ActivityId = data.ActivityId,
ParentActivityId = data.RelatedActivityId,
Nested = bindOperations.ContainsKey(data.RelatedActivityId)
};
string requestingAssembly = GetDataString("RequestingAssembly");
if (!string.IsNullOrEmpty(requestingAssembly))
bindOperation.Nested = bindOperations.ContainsKey(data.RelatedActivityId);
bindOperations.Add(data.ActivityId, bindOperation);
if (bindOperation.Nested)
{
bindOperation.RequestingAssembly = new AssemblyName(requestingAssembly);
bindOperations[data.RelatedActivityId].NestedBinds.Add(bindOperation);
}
bindOperations.Add(data.ActivityId, bindOperation);
}
break;
}
case "AssemblyLoadStop":
{
lock (eventsLock)
{
Assert.IsTrue(bindOperations.ContainsKey(data.ActivityId), "AssemblyLoadStop should have a matching AssemblyBindStart");
Expand All @@ -123,7 +164,68 @@ protected override void OnEventWritten(EventWrittenEventArgs data)
bind.Completed = true;
}
break;
}
case "AssemblyLoadContextResolvingHandlerInvoked":
{
HandlerInvocation handlerInvocation = ParseHandlerInvokedEvent(GetDataString);
lock (eventsLock)
{
Assert.IsTrue(bindOperations.ContainsKey(data.ActivityId), "AssemblyLoadContextResolvingHandlerInvoked should have a matching AssemblyBindStart");
BindOperation bind = bindOperations[data.ActivityId];
bind.AssemblyLoadContextResolvingHandlers.Add(handlerInvocation);
}
break;
}
case "AppDomainAssemblyResolveHandlerInvoked":
{
HandlerInvocation handlerInvocation = ParseHandlerInvokedEvent(GetDataString);
lock (eventsLock)
{
Assert.IsTrue(bindOperations.ContainsKey(data.ActivityId), "AppDomainAssemblyResolveHandlerInvoked should have a matching AssemblyBindStart");
BindOperation bind = bindOperations[data.ActivityId];
bind.AppDomainAssemblyResolveHandlers.Add(handlerInvocation);
}
break;
}
}
}

private BindOperation ParseAssemblyLoadStartEvent(EventWrittenEventArgs data, Func<string, string> getDataString)
{
var bindOperation = new BindOperation()
{
AssemblyName = new AssemblyName(getDataString("AssemblyName")),
AssemblyPath = getDataString("AssemblyPath"),
AssemblyLoadContext = getDataString("AssemblyLoadContext"),
RequestingAssemblyLoadContext = getDataString("RequestingAssemblyLoadContext"),
ActivityId = data.ActivityId,
ParentActivityId = data.RelatedActivityId,
};
string requestingAssembly = getDataString("RequestingAssembly");
if (!string.IsNullOrEmpty(requestingAssembly))
{
bindOperation.RequestingAssembly = new AssemblyName(requestingAssembly);
}

return bindOperation;
}

private HandlerInvocation ParseHandlerInvokedEvent(Func<string, string> getDataString)
{
var handlerInvocation = new HandlerInvocation()
{
AssemblyName = new AssemblyName(getDataString("AssemblyName")),
HandlerName = getDataString("HandlerName"),
AssemblyLoadContext = getDataString("AssemblyLoadContext"),
ResultAssemblyPath = getDataString("ResultAssemblyPath")
};
string resultName = getDataString("ResultAssemblyName");
if (!string.IsNullOrEmpty(resultName))
{
handlerInvocation.ResultAssemblyName = new AssemblyName(resultName);
}

return handlerInvocation;
}
}
}
Loading

0 comments on commit 3857ce6

Please sign in to comment.