diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerEventsAvailableNotification.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerEventsAvailableNotification.cs index 91ad3159..a244af58 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerEventsAvailableNotification.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerEventsAvailableNotification.cs @@ -14,6 +14,8 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler.Contracts public string OwnerUri { get; set; } public List Events { get; set; } + + public bool EventsLost { get; set; } } public class ProfilerEventsAvailableNotification diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerSessionStoppedNotification.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerSessionStoppedNotification.cs new file mode 100644 index 00000000..55ec5efc --- /dev/null +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/Contracts/ProfilerSessionStoppedNotification.cs @@ -0,0 +1,25 @@ +// +// Copyright (c) Microsoft. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. +// + +using System.Collections.Generic; +using Microsoft.SqlTools.Hosting.Protocol.Contracts; +using Microsoft.SqlTools.ServiceLayer.Utility; + +namespace Microsoft.SqlTools.ServiceLayer.Profiler.Contracts +{ + public class ProfilerSessionStoppedParams + { + public string OwnerUri { get; set; } + + public int SessionId { get; set; } + } + + public class ProfilerSessionStoppedNotification + { + public static readonly + EventType Type = + EventType.Create("profiler/sessionstopped"); + } +} diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/IProfilerSessionListener.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/IProfilerSessionListener.cs index 846f3a36..0b0b53bd 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Profiler/IProfilerSessionListener.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/IProfilerSessionListener.cs @@ -10,6 +10,8 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler { public interface IProfilerSessionListener { - void EventsAvailable(string sessionId, List events); + void EventsAvailable(string sessionId, List events, bool eventsLost); + + void SessionStopped(string viewerId, int sessionId); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerService.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerService.cs index 169030ff..cd0640c1 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerService.cs @@ -268,7 +268,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler /// /// Callback when profiler events are available /// - public void EventsAvailable(string sessionId, List events) + public void EventsAvailable(string sessionId, List events, bool eventsLost) { // pass the profiler events on to the client this.ServiceHost.SendEvent( @@ -276,7 +276,23 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler new ProfilerEventsAvailableParams() { OwnerUri = sessionId, - Events = events + Events = events, + EventsLost = eventsLost + }); + } + + /// + /// Callback when the XEvent session is closed unexpectedly + /// + public void SessionStopped(string viewerId, int sessionId) + { + // notify the client that their session closed + this.ServiceHost.SendEvent( + ProfilerSessionStoppedNotification.Type, + new ProfilerSessionStoppedParams() + { + OwnerUri = viewerId, + SessionId = sessionId }); } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSession.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSession.cs index 66a73bf2..4d04fb38 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSession.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSession.cs @@ -24,6 +24,9 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler private TimeSpan pollingDelay = DefaultPollingDelay; private ProfilerEvent lastSeenEvent = null; + private bool eventsLost = false; + int lastSeenId = -1; + public bool pollImmediatly = false; /// @@ -87,6 +90,17 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler } } + /// + /// Could events have been lost in the last poll + /// + public bool EventsLost + { + get + { + return this.eventsLost; + } + } + /// /// Determine if an event was caused by the XEvent polling queries /// @@ -129,13 +143,19 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler /// public void FilterOldEvents(List events) { - if (lastSeenEvent != null) + 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; @@ -148,11 +168,18 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler { 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 @@ -161,6 +188,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler if (events.Count > 0) { lastSeenEvent = events.LastOrDefault(); + lastSeenId = int.Parse(lastSeenEvent.Values["event_sequence"]); } // ignore all events before the session began diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs index a8bd72a9..42e6311d 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs @@ -233,7 +233,8 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler Task.Factory.StartNew(() => { var events = PollSession(session); - if (events.Count > 0) + bool eventsLost = session.EventsLost; + if (events.Count > 0 || eventsLost) { // notify all viewers for the polled session List viewerIds = this.sessionViewers[session.XEventSession.Id]; @@ -241,7 +242,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler { if (allViewers[viewerId].active) { - SendEventsToListeners(viewerId, events); + SendEventsToListeners(viewerId, events, eventsLost); } } } @@ -274,9 +275,15 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler } } } + catch (XEventException) + { + SendStoppedSessionInfoToListeners(session.XEventSession.Id); + ProfilerSession tempSession; + RemoveSession(session.XEventSession.Id, out tempSession); + } catch (Exception ex) { - Logger.Write(LogLevel.Warning, "Failed to pool session. error: " + ex.Message); + Logger.Write(LogLevel.Warning, "Failed to poll session. error: " + ex.Message); } finally { @@ -288,15 +295,32 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler } /// - /// Notify listeners when new profiler events are available + /// Notify listeners about closed sessions /// - private void SendEventsToListeners(string sessionId, List events) + private void SendStoppedSessionInfoToListeners(int sessionId) { lock (listenersLock) { foreach (var listener in this.listeners) { - listener.EventsAvailable(sessionId, events); + foreach(string viewerId in sessionViewers[sessionId]) + { + listener.SessionStopped(viewerId, sessionId); + } + } + } + } + + /// + /// Notify listeners when new profiler events are available + /// + private void SendEventsToListeners(string sessionId, List events, bool eventsLost) + { + lock (listenersLock) + { + foreach (var listener in this.listeners) + { + listener.EventsAvailable(sessionId, events, eventsLost); } } } diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs index 24740383..46963953 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs @@ -46,7 +46,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler // capture listener event notifications var mockListener = new Mock(); - mockListener.Setup(p => p.EventsAvailable(It.IsAny(), It.IsAny>())).Callback(() => + mockListener.Setup(p => p.EventsAvailable(It.IsAny(), It.IsAny>(), It.IsAny())).Callback(() => { recievedEvents = true; }); @@ -166,7 +166,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler // capture listener event notifications var mockListener = new Mock(); - mockListener.Setup(p => p.EventsAvailable(It.IsAny(), It.IsAny>())).Callback(() => + mockListener.Setup(p => p.EventsAvailable(It.IsAny(), It.IsAny>(), It.IsAny())).Callback(() => { recievedEvents = true; }); @@ -235,5 +235,52 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler requestContext.VerifyAll(); } + + /// + /// Test notifications for stopped sessions + /// + [Fact] + public async Task TestStoppedSessionNotification() + { + bool sessionStopped = false; + string testUri = "profiler_uri"; + + // capture listener event notifications + var mockSession = new Mock(); + mockSession.Setup(p => p.GetTargetXml()).Callback(() => + { + throw new XEventException(); + }); + + var mockListener = new Mock(); + mockListener.Setup(p => p.SessionStopped(It.IsAny(), It.IsAny())).Callback(() => + { + sessionStopped = true; + }); + + var profilerService = new ProfilerService(); + profilerService.SessionMonitor.AddSessionListener(mockListener.Object); + profilerService.ConnectionServiceInstance = TestObjects.GetTestConnectionService(); + ConnectionInfo connectionInfo = TestObjects.GetTestConnectionInfo(); + profilerService.ConnectionServiceInstance.OwnerToConnectionMap.Add(testUri, connectionInfo); + + // start monitoring test session + profilerService.SessionMonitor.StartMonitoringSession(testUri, mockSession.Object); + + // wait for polling to finish, or for timeout + System.Timers.Timer pollingTimer = new System.Timers.Timer(); + pollingTimer.Interval = 10000; + pollingTimer.Start(); + bool timeout = false; + pollingTimer.Elapsed += new System.Timers.ElapsedEventHandler((s_, e_) => {timeout = true;}); + while (sessionStopped == false && !timeout) + { + Thread.Sleep(250); + } + pollingTimer.Stop(); + + // check that a stopped session notification was sent + Assert.True(sessionStopped); + } } } diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerSessionTests.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerSessionTests.cs index b43f77ce..92509260 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerSessionTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerSessionTests.cs @@ -34,6 +34,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler // add a new event var newEvent = new ProfilerEvent("new event", "1/1/2017"); + newEvent.Values.Add("event_sequence", "4"); allEvents.Add(newEvent); // poll all events @@ -52,7 +53,6 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler Assert.Equal(profilerEvents.Count, 0); } - /// /// Test the FilterProfilerEvents method /// @@ -68,6 +68,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler // 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"); + newEvent.Values.Add("event_sequence", "4"); profilerEvents.Add(newEvent); // verify that the polling event is removed @@ -76,6 +77,53 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler Assert.Equal(newProfilerEvents.Count, expectedEventCount); } + /// + /// Test notifications for lost events + /// + [Fact] + 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); + } + /// /// Test the TryEnterPolling method /// diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerTestObjects.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerTestObjects.cs index f05adeef..b69010cd 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerTestObjects.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerTestObjects.cs @@ -25,11 +25,18 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler { get { + ProfilerEvent event1 = new ProfilerEvent("event1", "1/1/2017"); + event1.Values.Add("event_sequence", "1"); + ProfilerEvent event2 = new ProfilerEvent("event2", "1/2/2017"); + event2.Values.Add("event_sequence", "2"); + ProfilerEvent event3 = new ProfilerEvent("event3", "1/3/2017"); + event3.Values.Add("event_sequence", "3"); + return new List { - new ProfilerEvent("event1", "1/1/2017"), - new ProfilerEvent("event2", "1/2/2017"), - new ProfilerEvent("event3", "1/3/2017") + event1, + event2, + event3 }; } } @@ -41,11 +48,18 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler public List PreviousEvents { get; set; } - public void EventsAvailable(string sessionId, List events) + public bool Stopped { get; set; } + + public void EventsAvailable(string sessionId, List events, bool eventsLost) { this.PreviousSessionId = sessionId; this.PreviousEvents = events; } + + public void SessionStopped(string viewerId, int sessionId) + { + Stopped = true; + } } public class TestXEventSession : IXEventSession @@ -210,6 +224,10 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler " " + " 1" + " " + + " " + + " " + + " 1" + + " " + " " + ""; @@ -220,12 +238,20 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler " " + " 1" + " " + + " " + + " " + + " 1" + + " " + " " + " " + " " + " " + " 1" + " " + + " " + + " " + + " 2" + + " " + " " + ""; @@ -236,18 +262,30 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler " " + " 1" + " " + + " " + + " " + + " 1" + + " " + " " + " " + " " + " " + " 1" + " " + + " " + + " " + + " 2" + + " " + " " + " " + " " + " " + " 1" + " " + + " " + + " " + + " 3" + + " " + " " + ""; @@ -277,6 +315,10 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler " " + " 2" + " " + + " " + + " " + + " 1" + + " " + " " + ""; @@ -287,12 +329,20 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler " " + " 2" + " " + + " " + + " " + + " 1" + + " " + " " + " " + " " + " " + " 2" + " " + + " " + + " " + + " 2" + + " " + " " + ""; @@ -303,18 +353,30 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler " " + " 2" + " " + + " " + + " " + + " 1" + + " " + " " + " " + " " + " " + " 2" + " " + + " " + + " " + + " 2" + + " " + " " + " " + " " + " " + " 2" + " " + + " " + + " " + + " 3" + + " " + " " + "";