[02/02 11:21:22,Telerik.TestStudio.exe(6988:1)] First trace message from process 6988: "C:\Program Files (x86)\Telerik\Test Studio\Bin\Telerik.TestStudio.exe" 
[02/02 11:21:22,Telerik.TestStudio.exe(6988:1)] First trace message from foreground thread "Application start thread" (managed ID = 1, native ID = 5832).
[02/02 11:21:22,Telerik.TestStudio.exe(6988:1),Framework] Manager.get_ActiveBrowser() : The current ActiveBrowser is either invisible or disconnected.
[02/02 11:21:22,ArtOfTest.Runner.exe(3968:3)] First trace message from process 3968: "C:\Program Files (x86)\Telerik\Test Studio\Bin\ArtOfTest.Runner.exe"  /controller /parentprocesshandle=3972
[02/02 11:21:22,ArtOfTest.Runner.exe(3968:3)] First trace message from foreground thread "Remote.ArtOfTest.Runner.Listener" (managed ID = 3, native ID = 4036).
[02/02 11:21:22,ArtOfTest.Runner.exe(3968:3),Uncategorized] Loader.LoadTranslatorGroups() : ------- Function Start -------
[02/02 11:21:22,ArtOfTest.Runner.exe(3968:3),Uncategorized] Loader.LoadTranslatorGroups() : Translators Directory is : C:\Program Files (x86)\Telerik\Test Studio\Bin\Translators
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:3),Uncategorized] Loader.LoadTranslatorGroups() : ------- Function End -------
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5)] First trace message from pool unnamed thread (managed ID = 5, native ID = 4612).
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] InternetExplorerActions.LaunchNewBrowserInstance() : Process launched (ID=4160, Path="C:\Program Files\Internet Explorer\iexplore.exe", Arguments="-nomerge about:blank").
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] InternetExplorerActions.LaunchNewBrowserInstance() : Attempting to attach on IE frame (HWND=197206)...
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] Connector.Start() : Process launched (ID=940, Path="C:\Windows\SysWOW64\rundll32.exe", Arguments="ArtOfTest.Connector.dll,AttachToWindowEntryPoint 852562").
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] Connector.Start() : Process exited (ID=940, ExitCode=0, Path="C:\Windows\SysWOW64\rundll32.exe", Arguments="ArtOfTest.Connector.dll,AttachToWindowEntryPoint 852562").
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] InternetExplorerActions.LaunchNewBrowserInstance() : Process "Telerik.TestStudio" (ID=6988) is assumed to host the controller.
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] Connector.InjectCode() : ------- Function Start -------
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] Connector.InjectCode() : Connection string: C:\Windows\Microsoft.Net\assembly\GAC_MSIL\ArtOfTest.InternetExplorer\v4.0_2014.3.903.0__5339893a7cefe4d6\ArtOfTest.InternetExplorer.dll?ArtOfTest.InternetExplorer.ArtOfTestPluginEntryPoint?6988
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:5),Framework] InternetExplorerActions.WaitForDocument() : Attempting to get IHTMLDocument2 from Internet Explorer HWND 852562 on another thread...
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:6)] First trace message from pool thread "WaitAsync polling wait worker" (managed ID = 6, native ID = 2740).
[02/02 11:21:24,ArtOfTest.Runner.exe(3968:6),Framework] <>c__DisplayClassf.<WaitForDocument>b__8() : Attempting to get document from window handle
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Framework] InternetExplorerActions.WaitForDocument() : IHTMLDocument2 successfully retrieved.
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Framework] Connector.InjectCode() : Sending WM_COPYDATA to HWND 852562 (lpData = "C:\Windows\Microsoft.Net\assembly\GAC_MSIL\ArtOfTest.InternetExplorer\v4.0_2014.3.903.0__5339893a7cefe4d6\ArtOfTest.InternetExplorer.dll?ArtOfTest.InternetExplorer.ArtOfTestPluginEntryPoint?6988")...
[02/02 11:21:25,IEXPLORE.EXE(6392:1)] First trace message from process 6392: "C:\Program Files (x86)\Internet Explorer\IEXPLORE.EXE" SCODEF:4160 CREDAT:275457 /prefetch:2
[02/02 11:21:25,IEXPLORE.EXE(6392:1)] First trace message from background unnamed thread (managed ID = 1, native ID = 5956).
[02/02 11:21:25,IEXPLORE.EXE(6392:1),Framework] ArtOfTestPluginEntryPoint.Connect() : The .NET Framework is now active inside the hooked process (HWND = 852562, PipeName = "Pipe.ArtOfTest.WebAii.BrowserProvisioner_-1962204533", PID = 6988).
[02/02 11:21:25,IEXPLORE.EXE(6392:1),Framework] InternetExplorerActions.WaitForDocument() : Attempting to get IHTMLDocument2 from Internet Explorer HWND 852562 on same thread...
[02/02 11:21:25,IEXPLORE.EXE(6392:1),Framework] InternetExplorerActions.WaitForDocument() : IHTMLDocument2 successfully retrieved.
[02/02 11:21:25,IEXPLORE.EXE(6392:1),Framework] BrowserRemoteClient constructor : The client ID for this hooked process will be "Client_7401fc92-f1e3-42fe-a064-bab614cf956c".
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:7)] First trace message from background thread "Pipe.ArtOfTest.WebAii.BrowserProvisioner" (managed ID = 7, native ID = 4544).
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:7),Framework] BrowserProvisioner.ServiceThread() : A new client has connected to the provisioning pipe.
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:13)] First trace message from background thread "Remoted async command listener" (managed ID = 13, native ID = 6692).
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:13),Framework] BrowserRemoted.AsyncListenerThreadEntry() : Not connected; this will now wait indefinitely for a pipe client connection...
[02/02 11:21:25,IEXPLORE.EXE(6392:1),Framework] BrowserRemoteClient.CreateNamedPipes() : Named pipes created for communication with the server: {Command = "7735eaad-0c93-4300-b85c-c4501a473cd5.CommandPipe", Async = "7735eaad-0c93-4300-b85c-c4501a473cd5.AsyncPipe"}
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:13),Framework] BrowserRemoted.AsyncListenerThreadEntry() : A new client has connected to the pipe.
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:13),Framework] BrowserRemoted.AsyncListenerThreadEntry() : Now waiting indefinitely for a command from the pipe client...
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:7),Framework] Manager.AddNewBrowser() : Added client ID "Client_7401fc92-f1e3-42fe-a064-bab614cf956c" (now there is/are 1 total).
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Framework] Connector.InjectCode() : Returned from sending WM_COPYDATA (LRESULT=0, GetLastError()=ERROR_ALREADY_EXISTS).
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Framework] Connector.InjectCode() : ------- Function End -------
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Execution] ExecutionEngine.InternalExecuteTest() : Executing test: 'WebTest', path: 'WebTest.tstest.'
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Execution] ExtensionsManager.LoadExtensions() : ------- Function Start -------
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Got 9 plugin(s) in folder "C:\Program Files (x86)\Telerik\Test Studio\Bin\Plugins".
[02/02 11:21:25,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Jira.BugTracking.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Load.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Manual.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.OTA.Interop.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Plugins.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Shared.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.TeamPulse.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Web.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Wpf.dll" from plugins folder.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Execution] ExtensionsManager.LoadExtensions() : ------- Function End -------
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),DialogPlayback] DialogMonitor.Start() : Beginning monitoring for dialogs from the set {}.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.SetCurrentStep() : VisualDebugger::SetCurrentStep
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::Start
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::End
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:12)] First trace message from background thread "UAI Dispatcher Thread" (managed ID = 12, native ID = 336).
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:12),UIAutomation] AutomationExtensions.AddStructureChangedEventHandler() : Added a structure change handler on element System.Windows.Automation.AutomationElement scope Subtree.
[02/02 11:21:26,ArtOfTest.Runner.exe(3968:5),Execution] ExecutionEngine.NotifyBeforeStepExecuted() : Executing step 1 "Navigate to : 'http://www.google.com/'"...
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),Execution] ExecutionEngine.NotifyAfterStepExecuted() : Finished executing step 1 "Navigate to : 'http://www.google.com/'".
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::Start
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::End
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.SetCurrentStep() : VisualDebugger::SetCurrentStep
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::Start
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::End
[02/02 11:21:27,ArtOfTest.Runner.exe(3968:5),Execution] ExecutionEngine.NotifyBeforeStepExecuted() : Executing step 2 "[WebTest_CodedStep] : New Coded Step"...
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::Start
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::BreakOnFail
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.CheckPause() : VisualDebugger::CheckPause::End
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.ShutDown() : VisualDebbuger::ShutDown::Start
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Uncategorized] AdornerWindow.ShutDown() : AdornerWnd::ShutDown::Start
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Uncategorized] AdornerWindow.ShutDown() : AdornerWnd::DetachWrappedWindow::Start
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Uncategorized] AdornerWindow.ShutDown() : AdornerWnd::DetachWrappedWindow::End
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Uncategorized] AdornerWindow.ShutDown() : AdornerWnd::DispatcherBeginInvokeShutdown::Start
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Uncategorized] AdornerWindow.ShutDown() : AdornerWnd::Close::Start
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),TestStudio] VisualDebugger.ShutDown() : VisualDebbuger::ShutDown::End
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Framework] BrowserProvisioner.EndService() : Connecting to the provisioning pipe "Pipe.ArtOfTest.WebAii.BrowserProvisioner_-1962204533" in order to unblock and eventually terminate it...
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Framework] BrowserProvisioner.EndService() : Provisioning pipe connected.
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:7),Framework] BrowserProvisioner.ServiceThread() : A new client has connected to the provisioning pipe but this will be treated as a termination cue.
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Framework] BrowserProvisioner.EndService() : Provisioning thread terminated.
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),DialogPlayback] DialogMonitor.AddDialog() : Added {OnBeforeUnloadDialog(Dismiss=OK)} for monitoring.
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Framework] Manager.RemoveBrowser() : Removed client ID "Client_7401fc92-f1e3-42fe-a064-bab614cf956c" (0 remaining).
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Framework] Manager.SetActiveBrowser() : Active browser is now null.
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:5),Framework] BrowserRemoted.End() : Now aborting the listener thread (TID = 13).
[02/02 11:21:57,IEXPLORE.EXE(6392:1),Framework] BrowserRemoteClient.Disconnect() : Sending ClientDisconnectRequest(ClientId="Client_7401fc92-f1e3-42fe-a064-bab614cf956c") to pipe server...
[02/02 11:21:57,IEXPLORE.EXE(6392:1),Framework] BrowserRemoteClient.Disconnect() : Command pipe is already disconnected.
[02/02 11:21:57,ArtOfTest.Runner.exe(3968:13),Warning] PipeCommunication.SyncPipeRead() : Pipe read broken by thread-abort.
[02/02 11:21:58,ArtOfTest.Runner.exe(3968:12),Framework] Manager.get_ActiveBrowser() : The current ActiveBrowser is either invisible or disconnected.
[02/02 11:21:58,ArtOfTest.Runner.exe(3968:12),Framework] Manager.get_ActiveBrowser() : The current ActiveBrowser is either invisible or disconnected.
[02/02 11:22:01,ArtOfTest.Runner.exe(3968:5),DialogPlayback] DialogMonitor.Stop() : Dialog monitoring is being halted.
[02/02 11:22:01,ArtOfTest.Runner.exe(3968:12),UIAutomation] AutomationExtensions.RemoveStructureChangedEventHandler() : Removed the structure change handler on element System.Windows.Automation.AutomationElement scope Subtree.
[02/02 11:22:01,ArtOfTest.Runner.exe(3968:5),UIAutomation] AutomationExtensions.AddAutomationEventHandler() : Added a(n) WindowPatternIdentifiers.WindowOpenedProperty handler on element System.Windows.Automation.AutomationElement scope Descendants.
[02/02 11:22:01,Telerik.TestStudio.exe(6988:21)] First trace message from background thread "Callback Listener Thread" (managed ID = 21, native ID = 4664).
[02/02 11:22:01,Telerik.TestStudio.exe(6988:21),Warning] PipeCommunication.SyncPipeRead() : Pipe was already disposed at the moment of the read attempt.
