Debug.Assert exception I encountered when using Debug version System.Private.CoreLib.dll with mono runtime #96324
Assignees
Labels
area-System.Diagnostics.Tracing
needs-author-action
An issue or pull request that requires more info or actions from the author.
runtime-mono
specific to the Mono runtime
Comments
ghost
added
the
|
Tagging subscribers to this area: @tarekgh, @tommcdon, @pjanotti Issue DetailsDescriptionI was testing integrating the Mono Runtime into my C++ application and encountered the following problem during the initialization phase: at System.Diagnostics.DebugProvider.Fail(String message, String detailMessage)
at System.Diagnostics.Debug.Fail(String message, String detailMessage)
at System.Diagnostics.Debug.Assert(Boolean condition, String message, String detailMessage)
at System.Diagnostics.Debug.Assert(Boolean condition, String message)
at System.Diagnostics.Debug.Assert(Boolean condition, AssertInterpolatedStringHandler& message)
at System.Diagnostics.Tracing.CounterGroup.OnEventSourceCommand(Object sender, EventCommandEventArgs e)
at System.Diagnostics.Tracing.EventSource.add_EventCommandExecuted(EventHandler`1 value)
at System.Diagnostics.Tracing.CounterGroup.RegisterCommandCallback()
at System.Diagnostics.Tracing.CounterGroup..ctor(EventSource eventSource)
at System.Diagnostics.Tracing.CounterGroup.GetCounterGroup(EventSource eventSource)
at System.Diagnostics.Tracing.DiagnosticCounter.Publish()
at System.Diagnostics.Tracing.PollingCounter..ctor(String name, EventSource eventSource, Func`1 metricProvider)
at System.Diagnostics.Tracing.RuntimeEventSource.OnEventCommand(EventCommandEventArgs command)
at System.Diagnostics.Tracing.EventSource.DoCommand(EventCommandEventArgs commandArgs)
at System.Diagnostics.Tracing.EventSource.Initialize(Guid eventSourceGuid, String eventSourceName, String[] traits)
at System.Diagnostics.Tracing.EventSource..ctor(Guid eventSourceGuid, String eventSourceName, EventSourceSettings settings, String[] traits)
at System.Diagnostics.Tracing.EventSource..ctor(Guid eventSourceGuid, String eventSourceName)
at System.Diagnostics.Tracing.RuntimeEventSource..ctor()
at System.Diagnostics.Tracing.RuntimeEventSource.Initialize()In order to find this problem, I modified the source code locally and output the log when necessary. The code modification is as follows: public event EventHandler<EventCommandEventArgs>? EventCommandExecuted
{
add
{
if (value == null)
return;
Debug.WriteLine($"EventSource[{GetHashCode()}] add new one {value}({value.GetHashCode()}) from {System.Environment.StackTrace}");
m_eventCommandExecuted += value;
// If we have an EventHandler<EventCommandEventArgs> attached to the EventSource before the first command arrives
// It should get a chance to handle the deferred commands.
EventCommandEventArgs? deferredCommands = m_deferredCommands;
while (deferredCommands != null)
{
Debug.WriteLine($"EventSource[{GetHashCode()}]Invoke deferred command on this value:{deferredCommands}({deferredCommands.GetHashCode()} Command = {deferredCommands.Command})");
value(this, deferredCommands);
deferredCommands = deferredCommands.nextCommand;
}
}
remove
{
Debug.WriteLine($"EventSource[{GetHashCode()}] remove one {value} from {System.Environment.StackTrace}");
m_eventCommandExecuted -= value;
}
}internal void SendCommand(EventListener? listener, EventProviderType eventProviderType, int perEventSourceSessionId,
EventCommand command, bool enable,
EventLevel level, EventKeywords matchAnyKeyword,
IDictionary<string, string?>? commandArguments)
{
if (!IsSupported)
{
return;
}
var commandArgs = new EventCommandEventArgs(command, commandArguments, this, listener, eventProviderType, perEventSourceSessionId, enable, level, matchAnyKeyword);
lock (EventListener.EventListenersLock)
{
if (m_completelyInited)
{
// After the first command arrive after construction, we are ready to get rid of the deferred commands
this.m_deferredCommands = null;
// We are fully initialized, do the command
DoCommand(commandArgs);
}
else
{
Debug.WriteLine($"EventSource[{GetHashCode()}] Add {commandArgs} {commandArgs.GetHashCode()} Command={commandArgs.Command} to m_deferredCommands in SendCommand:\r\n{System.Environment.StackTrace}");
// We can't do the command, simply remember it and we do it when we are fully constructed.
if (m_deferredCommands == null)
{
m_deferredCommands = commandArgs; // create the first entry
}
else
{
// We have one or more entries, find the last one and add it to that.
EventCommandEventArgs lastCommand = m_deferredCommands;
while (lastCommand.nextCommand != null)
lastCommand = lastCommand.nextCommand;
lastCommand.nextCommand = commandArgs;
}
}
}
}I added the log and found that the reason was because some Update type Commands were added to m_deferredCommands in advance in EventSource.Initialize. When the code runs to CounterGroup.RegisterCommandCallback, it tries to trigger the command in m_deferredCommands, and then Assert is triggered. this code is invoked from native mono code:ep_rt_mono_init_finish void
ep_rt_mono_init_finish (void)
{
if (mono_runtime_get_no_exec ())
return;
// Managed init of diagnostics classes, like registration of RuntimeEventSource (if available).
ERROR_DECL (error);
MonoClass *runtime_event_source = mono_class_from_name_checked (mono_get_corlib (), "System.Diagnostics.Tracing", "RuntimeEventSource", error);
if (is_ok (error) && runtime_event_source) {
MonoMethod *init = mono_class_get_method_from_name_checked (runtime_event_source, "Initialize", -1, 0, error);
if (is_ok (error) && init) {
mono_runtime_try_invoke_handle (init, NULL_HANDLE, NULL, error);
}
}
mono_error_cleanup (error);
}Reproduction Steps
Expected behaviorno Debug.Assert Actual behavior Debug.Assert(e.Command == EventCommand.Enable || e.Command == EventCommand.Disable); in CounterGroup.OnEventSourceCommand. Regression?No response Known WorkaroundsNo response ConfigurationNo response Other informationNo response
|
bodong1987
changed the title
|
@lateralusX is this something that we should investigate in the mono implementation of eventpipe first? |
|
I can take a look, we run this code when running other versions of launchers embedding Mono on both desktop and mobile platforms, so I have not seen this issue in the other embedding scenarios, but need to take a close look to be sure. I know we had some changes around counter implementation in .net8 that potentially might have triggered some regression on Mono side, but we will see. I currently have some other things in pipe line before I can look at this, but try to get to it in coming weeks. |
hello. I found that this problem is indeed not a inevitable problem. If I encounter this problem, I only need to restart the operating system. And this problem seems to only occur on my Windows 10 machine. I have not encountered it on my other Windows 11 machine. EtwEventProvider.HandleEnableNotificationThis is triggered indirectly through the callback callback of the api calling Interop.Advapi32.EventRegister. protected override unsafe void HandleEnableNotification(
EventProvider target,
byte *additionalData,
byte level,
long matchAnyKeywords,
long matchAllKeywords,
Interop.Advapi32.EVENT_FILTER_DESCRIPTOR* filterData)
{
Debug.Assert(additionalData == null);
RuntimeEventSource.Log("EtwEventProvider HandleEnableNotification...");
// The GetSessions() logic was here to support the idea that different ETW sessions
// could have different user-defined filters. (I believe it is currently broken.)
//
// All this session based logic should be reviewed and likely removed, but that is a larger
// change that needs more careful staging.
List<KeyValuePair<SessionInfo, bool>> sessionsChanged = GetChangedSessions();
foreach (KeyValuePair<SessionInfo, bool> session in sessionsChanged)
{
int sessionChanged = session.Key.sessionIdBit;
bool bEnabling = session.Value;
// reinitialize args for every session...
IDictionary<string, string?>? args = null;
ControllerCommand command = ControllerCommand.Update;
RuntimeEventSource.Log("process session info: " + session.Key.etwSessionId + " " + session.Key.sessionIdBit + " bEnabling=" + bEnabling);
// read filter data only when a session is being *added*
if (bEnabling)
{
byte[]? filterDataBytes;
// if we get more than one session changed we have no way
// of knowing which one "filterData" belongs to
if (sessionsChanged.Count > 1 || filterData == null)
{
RuntimeEventSource.Log("TryReadRegistryFilterData...");
TryReadRegistryFilterData(session.Key.etwSessionId, out command, out filterDataBytes);
}
else
{
RuntimeEventSource.Log("MarshalFilterData...");
MarshalFilterData(filterData, out command, out filterDataBytes);
}
args = ParseFilterData(filterDataBytes);
}
RuntimeEventSource.Log("invoke OnControllerCommand, command = " + command.ToString());
// execute OnControllerCommand once for every session that has changed.
// If the sessionId argument is positive it will be sent to the EventSource as an Enable,
// and if it is negative it will be sent as a disable. See EventSource.DoCommand()
target.OnControllerCommand(command, args, bEnabling ? sessionChanged : -sessionChanged);
}
}
[UnmanagedCallersOnly]
private static unsafe void Callback(Guid* sourceId, int isEnabled, byte level,
long matchAnyKeywords, long matchAllKeywords, Interop.Advapi32.EVENT_FILTER_DESCRIPTOR* filterData, void* callbackContext)
{
RuntimeEventSource.Log("EtwEventProvider.Callback started... guid=" + (sourceId!=null? sourceId->ToString():""));
EtwEventProvider _this = (EtwEventProvider)GCHandle.FromIntPtr((IntPtr)callbackContext).Target!;
if (_this._eventProvider.TryGetTarget(out EventProvider? target))
{
_this.ProviderCallback(target, null, isEnabled, level, matchAnyKeywords, matchAllKeywords, filterData);
}
}
// Register an event provider.
internal override unsafe void Register(EventSource eventSource)
{
Debug.Assert(!_gcHandle.IsAllocated);
_gcHandle = GCHandle.Alloc(this);
long registrationHandle = 0;
_providerId = eventSource.Guid;
Guid providerId = _providerId;
RuntimeEventSource.Log($"EtwEventProvider.Register started... guid=" + providerId.ToString());
uint status = Interop.Advapi32.EventRegister(
&providerId,
&Callback,
(void*)GCHandle.ToIntPtr(_gcHandle),
®istrationHandle);
RuntimeEventSource.Log($"EtwEventProvider.Register finished... guid=" + providerId.ToString());
if (status != 0)
{
_gcHandle.Free();
throw new ArgumentException(Interop.Kernel32.GetMessage((int)status));
}
Debug.Assert(_registrationHandle == 0);
_registrationHandle = registrationHandle;
}With this information, what do you think? |
I have intercepted some logs during normal operation. You can see that during normal operation, no extra EventCommandEventArgs are created and added to m_deferredCommands in advance. I guess that's why, at some point, I run into this problem on my computer. If this problem occurs again later, I will output some more detailed logs. |
|
Hi @bodong1987, I'm trying to follow the stack traces and logging information you provided (which were helpful). If I am understanding correctly, during It looks like multiple and each of which would have their command changed to either hence, we see the logging statements in that section twice, where the second one hits the assert because the Command was not updated to Enable like the first one It seems like in both the stack traces where you demonstrate normal operation and one where there are extra commands added, that Are you still able to get a reliable repro, or after the restart, you don't see the assert fail anylonger? |
mdh1418
added
the
needs-author-action
|
This issue has been marked |
|
This issue has been automatically marked |
|
This issue will now be closed since it had been marked |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Description
I was testing integrating the Mono Runtime into my C++ application and encountered the following problem during the initialization phase:
In order to find this problem, I modified the source code locally and output the log when necessary. The code modification is as follows:
I added the log and found that the reason was because some Update type Commands were added to m_deferredCommands in advance in EventSource.Initialize. When the code runs to CounterGroup.RegisterCommandCallback, it tries to trigger the command in m_deferredCommands, and then Assert is triggered.
this code is invoked from native mono code:ep_rt_mono_init_finish
Reproduction Steps
Expected behavior
no Debug.Assert
Actual behavior
in CounterGroup.OnEventSourceCommand.
Regression?
No response
Known Workarounds
No response
Configuration
No response
Other information
No response
The text was updated successfully, but these errors were encountered: