private void StatusChanged()
{
if (Status.IsExiting)
{
return;
}
// update ICommand
CommandManager.InvalidateRequerySuggested();
// insert custom events
if (Settings.App.AddTraceStartEvent && Status.Status == AppStatusCodes.Running)
{
var item = new ProfilerEvent(EventClassType.Custom);
item.SetColumnValue(EventColumnType.TextData, "Trace started");
Events.Add(item);
}
if (Settings.App.AddTraceStopEvent && Status.Status == AppStatusCodes.Ready)
{
var item = new ProfilerEvent(EventClassType.Custom);
item.SetColumnValue(EventColumnType.TextData, "Trace stoped");
Events.Add(item);
}
}
/// <summary>
/// Filter the event list to not include previously seen events
/// </summary>
public List <ProfilerEvent> FilterOldEvents(List <ProfilerEvent> events)
{
if (lastSeenEvent != null)
{
// find the last event we've previously seen
bool foundLastEvent = false;
int idx = events.Count;
while (--idx >= 0)
{
if (events[idx].Equals(lastSeenEvent))
{
foundLastEvent = true;
break;
}
}
// remove all the events we've seen before
if (foundLastEvent)
{
events.RemoveRange(0, idx + 1);
}
}
// save the last event so we know where to clean-up the list from next time
if (events.Count > 0)
{
lastSeenEvent = events.LastOrDefault();
}
return(events);
}
private void DoWithProfiling(Action action, ProfilerEvent profilerEvent)
{
using (Profiler?.StartAuto(profilerEvent))
{
action();
}
}
// Populate an array of the active events, and add it to the timeline list of all captured audio frames.
private void CollectProfilerEvents(ProfilerEvent[] currentEvents)
{
List<ActiveEvent> activeEvents = UAudioManager.Instance.ProfilerEvents;
currentEvents = new ProfilerEvent[activeEvents.Count];
for (int i = 0; i < currentEvents.Length; i++)
{
ActiveEvent currentEvent = activeEvents[i];
ProfilerEvent tempEvent = new ProfilerEvent();
tempEvent.EventName = currentEvent.audioEvent.name;
tempEvent.EmitterName = currentEvent.AudioEmitter.name;
// The bus might be null, Unity defaults to Editor-hidden master bus.
if (currentEvent.audioEvent.bus == null)
{
tempEvent.BusName = "-MasterBus-";
}
else
{
tempEvent.BusName = currentEvent.audioEvent.bus.name;
}
currentEvents[i] = tempEvent;
}
this.eventTimeline.Add(currentEvents);
// Trim the first event if we have exceeded the maximum stored frames.
if (this.eventTimeline.Count > MaxFrames)
{
this.eventTimeline.RemoveAt(0);
}
this.currentFrame = this.eventTimeline.Count - 1;
}
private void WithProfiler(ProfilerEvent profEvent, Action action)
{
using (_profiler?.StartAuto(profEvent))
{
action();
}
}
protected FunctionCall CreateFunctionCall(ProfilerEvent entry)
{
FunctionCall newFunc;
newFunc = new FunctionCall(entry.Func);
return(newFunc);
}
public void TestFilterOldEvents()
{
// create a profiler session and get some test events
var profilerSession = new ProfilerSession();
var profilerEvents = ProfilerTestObjects.TestProfilerEvents;
// filter old events shouldn't filter any new events
var newProfilerEvents = profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(profilerEvents.Count, newProfilerEvents.Count);
// filter should now filter all the events since they've been seen before
newProfilerEvents = profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(newProfilerEvents.Count, 0);
// add a new event
var newEvent = new ProfilerEvent("new event", "1/1/2017");
profilerEvents.Add(newEvent);
// verify we only have the new event when reprocessing the event list
newProfilerEvents = profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(newProfilerEvents.Count, 1);
Assert.True(newProfilerEvents[0].Equals(newEvent));
// process whole list again and verify nothing new is available
newProfilerEvents = profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(newProfilerEvents.Count, 0);
}
// Populate an array of the active events, and add it to the timeline list of all captured audio frames.
private void CollectProfilerEvents(ProfilerEvent[] currentEvents)
{
List <ActiveEvent> activeEvents = UAudioManager.Instance.ProfilerEvents;
currentEvents = new ProfilerEvent[activeEvents.Count];
for (int i = 0; i < currentEvents.Length; i++)
{
ActiveEvent currentEvent = activeEvents[i];
ProfilerEvent tempEvent = new ProfilerEvent();
tempEvent.EventName = currentEvent.audioEvent.name;
tempEvent.EmitterName = currentEvent.AudioEmitter.name;
// The bus might be null, Unity defaults to Editor-hidden master bus.
if (currentEvent.audioEvent.bus == null)
{
tempEvent.BusName = "-MasterBus-";
}
else
{
tempEvent.BusName = currentEvent.audioEvent.bus.name;
}
currentEvents[i] = tempEvent;
}
this.eventTimeline.Add(currentEvents);
// Trim the first event if we have exceeded the maximum stored frames.
if (this.eventTimeline.Count > MaxFrames)
{
this.eventTimeline.RemoveAt(0);
}
this.currentFrame = this.eventTimeline.Count - 1;
}
public void TestFilterOldEvents()
{
// create a profiler session and get some test events
var profilerSession = new ProfilerSession();
var allEvents = ProfilerTestObjects.TestProfilerEvents;
var profilerEvents = ProfilerTestObjects.TestProfilerEvents;
// filter all the results from the first poll
// these events happened before the profiler began
profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(profilerEvents.Count, 0);
// add a new event
var newEvent = new ProfilerEvent("new event", "1/1/2017");
allEvents.Add(newEvent);
// poll all events
profilerEvents.AddRange(allEvents);
// filtering should leave only the new event
profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(profilerEvents.Count, 1);
Assert.True(profilerEvents[0].Equals(newEvent));
//poll again with no new events
profilerEvents.AddRange(allEvents);
// filter should now filter all the events since they've been seen before
profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(profilerEvents.Count, 0);
}
/// <summary>
/// Exports events to XML.
/// </summary>
/// <param name="Output">XML output.</param>
/// <param name="TimeUnit">Time unit to use.</param>
public void ExportXml(XmlWriter Output, TimeUnit TimeUnit)
{
Output.WriteStartElement("Thread");
Output.WriteAttributeString("name", this.name);
Output.WriteAttributeString("type", this.type.ToString());
Output.WriteStartElement("Events");
ProfilerEvent Prev = null;
foreach (ProfilerEvent Event in this.events)
{
Event.ExportXml(Output, Prev, TimeUnit);
Prev = Event;
}
Output.WriteEndElement();
foreach (ProfilerThread Thread in this.subThreads)
{
Thread.ExportXml(Output, TimeUnit);
}
Output.WriteEndElement();
}
private void FlushEvent()
{
_lastEvent = _buffer;
if (_lastEvent.IsInternal)
{
EventLog.Debug("internal");
}
}
private void NewEventArrived(ProfilerEvent evt, bool last)
{
if (string.IsNullOrEmpty(evt.TextData))
{
return;
}
_events.Add(evt);
addFilterEvent(evt);
checkFilterBoxItems();
}
/// <summary>
/// Filter the event list to not include previously seen events,
/// and to exclude events that happened before the profiling session began.
/// </summary>
public void FilterOldEvents(List <ProfilerEvent> events)
{
this.eventsLost = false;
if (lastSeenId != -1)
{
// find the last event we've previously seen
bool foundLastEvent = false;
int idx = events.Count;
int earliestSeenEventId = int.Parse(events.LastOrDefault().Values["event_sequence"]);
while (--idx >= 0)
{
// update the furthest back event we've found so far
earliestSeenEventId = Math.Min(earliestSeenEventId, int.Parse(events[idx].Values["event_sequence"]));
if (events[idx].Equals(lastSeenEvent))
{
foundLastEvent = true;
break;
}
}
// remove all the events we've seen before
if (foundLastEvent)
{
events.RemoveRange(0, idx + 1);
}
else if (earliestSeenEventId > (lastSeenId + 1))
{
// if there's a gap between the expected next event sequence
// and the furthest back event seen, we know we've lost events
this.eventsLost = true;
}
// save the last event so we know where to clean-up the list from next time
if (events.Count > 0)
{
lastSeenEvent = events.LastOrDefault();
lastSeenId = int.Parse(lastSeenEvent.Values["event_sequence"]);
}
}
else // first poll at start of session, all data is old
{
// save the last event as the beginning of the profiling session
if (events.Count > 0)
{
lastSeenEvent = events.LastOrDefault();
lastSeenId = int.Parse(lastSeenEvent.Values["event_sequence"]);
}
// ignore all events before the session began
events.Clear();
}
}
protected FunctionCall GetEnteredFunction(ProfilerEvent entry)
{
FunctionCall enterFunc;
if (!Functions.TryGetValue(entry.Func.Id, out enterFunc))
{
enterFunc = CreateFunctionCall(entry);
Functions.Add(enterFunc.Id, enterFunc);
}
return(enterFunc);
}
/// <summary>
/// Process DB reader data
/// </summary>
/// <returns>
/// Status of the processed event:
/// - "updating" - (still building full event);
/// - "new-event" meaning all data was received and the event is fully read;
/// </returns>
private ProfilerEventStatus ProcessEvent()
{
// event codes:
// 65534 Trace start
// 65528 First file in trace sequence, seems to appear after all the existing connections events. A bit like this is the start of the live events.
// 65527 Trace Rollover (i.e.a new file has been started
// 65533 Trace Stop
// 65526 start/flush
// column ID and event ID are always present, read them
int columnId = Convert.ToInt32(_dbReader[0]);
var buffer = new byte[2];
_dbReader.GetBytes(2, 0, buffer, 0, 2);
int eventClassId = (buffer[0]) | (buffer[1] << 8);
EventLog.Debug($"ProcessEvent: {eventClassId}/{columnId}");
// column of 65526, indicates a start/flush event, meaning:
// new trace event is about to happen, thus the current event won't retrieve more data and we can return it as processed
if (columnId == 65526)
{
EventLog.Debug("FLUSH");
// even is complete
FlushEvent();
_buffer = new ProfilerEvent((EventClassType)eventClassId);
return(ProfilerEventStatus.NewEvent);
}
// continuation of the same trace event
// find a column for this event, and set/read the value
var columnDefinition = EventDefinition.Instance.Columns.FirstOrDefault(x => (int)x.ColumnType == columnId);
if (columnDefinition != null)
{
_buffer.SetColumnValue(columnDefinition.ColumnType, columnDefinition.Process(_dbReader));
}
else
{
EventLog.Debug($"Column was not found; ColumnId: {columnId}");
}
return(ProfilerEventStatus.Update);
}
/// <summary>
/// Determine if an event was caused by the XEvent polling queries
/// </summary>
private bool IsProfilerEvent(ProfilerEvent currentEvent)
{
if (string.IsNullOrWhiteSpace(currentEvent.Name) || currentEvent.Values == null)
{
return(false);
}
if ((currentEvent.Name.Equals("sql_batch_completed") ||
currentEvent.Name.Equals("sql_batch_starting")) &&
currentEvent.Values.ContainsKey("batch_text"))
{
return(currentEvent.Values["batch_text"].Contains("SELECT target_data FROM sys.dm_xe_session_targets"));
}
return(false);
}
/// <summary>
/// Determines if the current object is equal to the <paramref name="obj"/>
/// </summary>
/// <param name="obj">The object to compare</param>
/// <returns>true, if the two instances are equal</returns>
public override bool Equals(object obj)
{
if (!(obj is ProfilerEvent))
{
return(false);
}
ProfilerEvent other = (ProfilerEvent)obj;
return(this.Type.Equals(other.Type) &&
this.SessionId.Equals(other.SessionId) &&
this.ObjectType.Equals(other.ObjectType) &&
this.ObjectId.Equals(other.ObjectId) && this.LineNo.Equals(other.LineNo) &&
this.StatementName.Equals(other.StatementName) &&
this.TimeStampRelativeMSec.Equals(other.TimeStampRelativeMSec));
}
private double WriteIfExist(StreamWriter sw, ProfilerEvent topEvent, SubEvents subEvents, int depth)
{
var profEvent = subEvents.TopEvent;
var stat = _analisisResult.FirstOrDefault(a => a.Code == (int)profEvent);
if (stat == null)
{
return(0);
}
var percent = PercentOfEvent(stat, topEvent);
for (int i = 0; i < depth; i++)
{
sw.Write("\t");
}
sw.WriteLine($"{profEvent.ToString().PadRight(30)} {stat.TotalTime.TotalSeconds:0.00000}, {percent:F1} %, {stat.TotalNumber} times");
if (subEvents.Events.Length != 0)
{
double subPercentSumm = 0;
sw.WriteLine();
foreach (var subEvent in subEvents.Events)
{
subPercentSumm += WriteIfExist(sw, subEvents.TopEvent, subEvent, depth + 1);
}
if (subPercentSumm != 0)
{
for (int i = 0; i < depth; i++)
{
sw.Write("\t");
}
sw.WriteLine("\t\t\t\t\t\t\tCovered: {0:F1}%", subPercentSumm);
}
sw.WriteLine();
}
return(percent);
}
public void TestEventsLost()
{
// create a profiler session and get some test events
var profilerSession = new ProfilerSession();
var profilerEvents = ProfilerTestObjects.TestProfilerEvents;
// filter all the results from the first poll
// these events happened before the profiler began
profilerSession.FilterOldEvents(profilerEvents);
Assert.Equal(profilerEvents.Count, 0);
// No events should be lost
Assert.False(profilerSession.EventsLost);
// test all events are overwritten, but no events are lost
profilerEvents.Clear();
ProfilerEvent newEvent = new ProfilerEvent("event4", "6/18/2018");
newEvent.Values.Add("event_sequence", "4");
profilerEvents.Add(newEvent);
profilerSession.FilterOldEvents(profilerEvents);
// should not show event loss
Assert.False(profilerSession.EventsLost);
// test all events are overwritten, and events are lost
profilerEvents.Clear();
newEvent = new ProfilerEvent("event7", "6/18/2018");
newEvent.Values.Add("event_sequence", "7");
profilerEvents.Add(newEvent);
profilerSession.FilterOldEvents(profilerEvents);
// should show event loss
Assert.True(profilerSession.EventsLost);
//poll again with previously seen events
profilerEvents.Add(newEvent);
// old events were seen, no event loss occured
profilerSession.FilterOldEvents(profilerEvents);
Assert.False(profilerSession.EventsLost);
}
public void TestFilterProfilerEvents()
{
// create a profiler session and get some test events
var profilerSession = new ProfilerSession();
var profilerEvents = ProfilerTestObjects.TestProfilerEvents;
int expectedEventCount = profilerEvents.Count;
// add a new "Profiler Polling" event
var newEvent = new ProfilerEvent("sql_batch_completed", "1/1/2017");
newEvent.Values.Add("batch_text", "SELECT target_data FROM sys.dm_xe_session_targets");
profilerEvents.Add(newEvent);
// verify that the polling event is removed
Assert.Equal(profilerEvents.Count, expectedEventCount + 1);
var newProfilerEvents = profilerSession.FilterProfilerEvents(profilerEvents);
Assert.Equal(newProfilerEvents.Count, expectedEventCount);
}
private void profilerThread(Object state)
{
try
{
while (!_stopRequested && _reader.TraceIsActive)
{
ProfilerEvent evt = _reader.Next();
if (evt != null)
{
lock (this)
{
_eventQueue.Enqueue(evt);
}
}
}
}
catch (Exception e)
{
}
}
// Only update the currently-playing events 10 times a second - we don't need millisecond-accurate profiling
private void OnInspectorUpdate()
{
if (!EditorApplication.isPlaying)
{
return;
}
ProfilerEvent[] currentEvents = new ProfilerEvent[0];
if (this.eventTimeline == null)
{
this.eventTimeline = new List <ProfilerEvent[]>();
}
if (UAudioManager.Instance != null && !EditorApplication.isPaused)
{
CollectProfilerEvents(currentEvents);
}
Repaint();
}
// Only update the currently-playing events 10 times a second - we don't need millisecond-accurate profiling
private void OnInspectorUpdate()
{
if (!EditorApplication.isPlaying)
{
return;
}
ProfilerEvent[] currentEvents = new ProfilerEvent[0];
if (this.eventTimeline == null)
{
this.eventTimeline = new List<ProfilerEvent[]>();
}
if (UAudioManager.Instance != null && !EditorApplication.isPaused)
{
CollectProfilerEvents(currentEvents);
}
Repaint();
}
private void addFilterEvent(ProfilerEvent evt)
{
bool add = true;
if (chkApplication.CheckBoxItems.Any(i => i.Checked) &&
!chkApplication.CheckBoxItems.Any(i => i.Checked && i.ComboBoxItem.ToString().Trim() == evt.ApplicationName.Trim()))
{
add = false;
}
if (chkLogin.CheckBoxItems.Any(i => i.Checked) &&
!chkLogin.CheckBoxItems.Any(i => i.Checked && i.ComboBoxItem.ToString().Trim() == evt.LoginName.Trim()))
{
add = false;
}
if (add)
{
_filtered.Add(evt);
}
}
/// <summary>
/// Registers trace with the database, opens command and DB data readers.
/// Setups events/columns to be captured
/// </summary>
public async Task RegisterTraceAsync(Dictionary <EventClassType, List <EventColumnType> > registeredEvents, CancellationToken cancel)
{
Log.Debug("Creating new trace");
_traceId = await DbTasks.CreateTraceAsync(_connection, cancel);
Log.Debug($"Trace ID: {_traceId}");
// prepare new buffer for receiving data
_buffer = new ProfilerEvent(EventClassType.Unknown);
// register each event-class
foreach (var evClass in registeredEvents.Keys)
{
cancel.ThrowIfCancellationRequested();
// convert all columns for this event-class into a flat array for registration
var columns = registeredEvents[evClass].Select(x => (int)x).ToArray();
try
{
Log.Debug($"Registering event ID: {evClass} with {columns.Count()} columns");
await DbTasks.SetEventAsync(_connection, cancel, _traceId.Value, (int)evClass, columns);
}
catch
{
Log.Warn($"Event registration failed. ID: {evClass}");
throw;
}
}
try
{
await DbTasks.ControlTraceAsync(_connection, _traceId.Value, 1 /* start */, cancel);
}
catch
{
Log.Warn("Cannot start registered trace");
throw;
}
}
/// <summary>
/// Filter the event list to not include previously seen events,
/// and to exclude events that happened before the profiling session began.
/// </summary>
public void FilterOldEvents(List <ProfilerEvent> events)
{
if (lastSeenEvent != null)
{
// find the last event we've previously seen
bool foundLastEvent = false;
int idx = events.Count;
while (--idx >= 0)
{
if (events[idx].Equals(lastSeenEvent))
{
foundLastEvent = true;
break;
}
}
// remove all the events we've seen before
if (foundLastEvent)
{
events.RemoveRange(0, idx + 1);
}
// save the last event so we know where to clean-up the list from next time
if (events.Count > 0)
{
lastSeenEvent = events.LastOrDefault();
}
}
else // first poll at start of session, all data is old
{
// save the last event as the beginning of the profiling session
if (events.Count > 0)
{
lastSeenEvent = events.LastOrDefault();
}
// ignore all events before the session began
events.Clear();
}
}
/// <summary>
/// Parse a single event node from XEvent XML
/// </summary>
private ProfilerEvent ParseProfilerEvent(XmlNode node)
{
var name = node.Attributes["name"];
var timestamp = node.Attributes["timestamp"];
var profilerEvent = new ProfilerEvent(name.InnerText, timestamp.InnerText);
foreach (XmlNode childNode in node.ChildNodes)
{
var childName = childNode.Attributes["name"];
XmlNode typeNode = childNode.SelectSingleNode("type");
var typeName = typeNode.Attributes["name"];
XmlNode valueNode = childNode.SelectSingleNode("value");
if (!profilerEvent.Values.ContainsKey(childName.InnerText))
{
profilerEvent.Values.Add(childName.InnerText, valueNode.InnerText);
}
}
return(profilerEvent);
}
private static TimeSpan GetTotalTime(ProfilerStatistics[] analisisResult, ProfilerEvent profEvent)
{
return(analisisResult.FirstOrDefault(a => a.Code == (int)profEvent)?.TotalTime ?? TimeSpan.Zero);
}
private static TimeSpan GetTimeSpan(ProfilerStatistics[] analisisResult, ProfilerEvent profEvent, int index)
{
return(analisisResult.FirstOrDefault(a => a.Code == (int)profEvent)?.Times[index] ?? TimeSpan.Zero);
}
private double PercentOfEvent(ProfilerStatistics subStat, ProfilerEvent mainEvent)
{
var mainStat = _analisisResult.First(a => a.Code == (int)mainEvent);
return((subStat.TotalTime.TotalSeconds / mainStat.TotalTime.TotalSeconds) * 100);
}
private double WriteTopLevelInfo(StreamWriter sw, ProfilerEvent topEvent, params ProfilerEvent[] events)
{
var subEvents = events.Select(ev => new SubEvents(ev)).ToArray();
return(WriteTopLevelInfo(sw, new SubEvents(topEvent, subEvents)));
}
private double WriteTopLevelInfo(StreamWriter sw, ProfilerEvent topEvent)
{
return(WriteTopLevelInfo(sw, new SubEvents(topEvent)));
}
private void DrawEventButton(ProfilerEvent currentEvent, int id)
{
EditorGUILayout.SelectableLabel(currentEvent.EventName + "-->(" + currentEvent.EmitterName + ")-->(" + currentEvent.BusName + ")");
}
