[11/07 12:36:04,Telerik.TestStudio.Scheduling.Client.exe(4644:13)] First trace message from pool unnamed thread (managed ID = 13, native ID = 4892).
[11/07 12:36:04,Telerik.TestStudio.Scheduling.Client.exe(4644:13),Framework] FireFoxInstallation.EnumFireFoxInstallations() : Valid Firefox 56.0.0.2 (x64) installation found at "C:\Program Files\Mozilla Firefox\firefox.exe".
[11/07 12:36:09,Telerik.TestStudio.ExecutionManagerService.exe(2484:12)] First trace message from pool unnamed thread (managed ID = 12, native ID = 4320).
[11/07 12:36:09,Telerik.TestStudio.ExecutionManagerService.exe(2484:12),Execution] JobBroker.ScheduleJobAsync() : Job satisfied all preconditions, id = 4e5e0a42-e33d-4fb5-bf85-4a47b5b26389
[11/07 12:36:09,Telerik.TestStudio.ExecutionManagerService.exe(2484:12),Execution] JobRunner.RunJobAsync() : TestList loaded for job ID = 4e5e0a42-e33d-4fb5-bf85-4a47b5b26389
[11/07 12:36:09,Telerik.TestStudio.ExecutionManagerService.exe(2484:12),Execution] JobRunner.RunJobAsync() : Job started, ID = 4e5e0a42-e33d-4fb5-bf85-4a47b5b26389
[11/07 12:36:09,Telerik.TestStudio.ExecutionManagerService.exe(2484:12),Execution] JobsController.CreateNewJob() : Accepted new job, Id = 4e5e0a42-e33d-4fb5-bf85-4a47b5b26389
[11/07 12:36:11,Telerik.TestStudio.RemoteExecutor.exe(4780:12)] First trace message from pool unnamed thread (managed ID = 12, native ID = 3444).
[11/07 12:36:11,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Execution] RunningTestsController.StartTest() : Test run requested for test with path 'ApoderadoValencia.tstest'. Project path: 'C:\Users\SebastianGI\Source\Repos\webvalenciarepo'.
[11/07 12:36:11,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Warning] CloudRunnableGUITestBuilder.CreateLocalCache() : Started getting project from storage
[11/07 12:36:11,Telerik.TestStudio.RemoteExecutor.exe(4780:18)] First trace message from pool unnamed thread (managed ID = 18, native ID = 4584).
[11/07 12:36:11,Telerik.TestStudio.RemoteExecutor.exe(4780:18),Execution] CloudStorageProjectOpener.DownloadAndSaveTestsAsync() : ------- Function Start -------
[11/07 12:36:14,Telerik.TestStudio.RemoteExecutor.exe(4780:19)] First trace message from pool unnamed thread (managed ID = 19, native ID = 4332).
[11/07 12:36:14,Telerik.TestStudio.RemoteExecutor.exe(4780:19),Execution] CloudStorageProjectOpener.DownloadAndSaveTestsAsync() : ------- Function End -------
[11/07 12:36:14,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Warning] CloudRunnableGUITestBuilder.CreateLocalCache() : Finished getting project from storage
[11/07 12:36:15,Telerik.TestStudio.RemoteExecutor.exe(4780:19),TestStudio] <>c__DisplayClass35_1.<LoadInternal>b__2() : Extract elements time: 00:00:00.1322824
[11/07 12:36:15,Telerik.TestStudio.RemoteExecutor.exe(4780:19),TestStudio] <>c__DisplayClass35_1.<LoadInternal>b__2() : Merge elements time: 00:00:00.0216503
[11/07 12:36:15,Telerik.TestStudio.RemoteExecutor.exe(4780:19),TestStudio] <>c__DisplayClass35_1.<LoadInternal>b__2() : Total Elements count: 80
[11/07 12:36:15,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Framework] TestAppLoader.LoadRefAssemblies() : External assembly loaded into the AppDomain: C:\Users\Automatismo\AppData\Local\Temp\Projects\8cb2c029-7312-43a6-a295-81f6268a0841\webvalenciarepo\..\webvalenciarepo\WinAPI.dll.
[11/07 12:36:15,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Framework] TestAppLoader.LoadRefAssemblies() : External assembly loaded into the AppDomain: C:\Users\Automatismo\AppData\Local\Temp\Projects\8cb2c029-7312-43a6-a295-81f6268a0841\webvalenciarepo\..\webvalenciarepo\Bcn.Comun.WebTest.dll.
[11/07 12:36:15,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Framework] TestAppLoader.LoadRefAssemblies() : External assembly loaded into the AppDomain: C:\Users\Automatismo\AppData\Local\Temp\Projects\8cb2c029-7312-43a6-a295-81f6268a0841\webvalenciarepo\..\webvalenciarepo\Bcn.Utils.dll.
[11/07 12:36:19,Telerik.TestStudio.RemoteExecutor.exe(4780:12),Framework] FireFoxInstallation.EnumFireFoxInstallations() : Valid Firefox 56.0.0.2 (x64) installation found at "C:\Program Files\Mozilla Firefox\firefox.exe".
[11/07 12:36:19,ArtOfTest.Runner.exe(3332:3)] First trace message from process 3332: "C:\Program Files (x86)\Telerik\Test Studio\Bin\ArtOfTest.Runner.exe"  /controller /parentprocesshandle=2524
[11/07 12:36:19,ArtOfTest.Runner.exe(3332:3)] First trace message from foreground thread "Remote.ArtOfTest.Runner.Listener" (managed ID = 3, native ID = 3272).
[11/07 12:36:19,ArtOfTest.Runner.exe(3332:3),TestStudio] Loader.LoadTranslatorGroups() : ------- Function Start -------
[11/07 12:36:20,ArtOfTest.Runner.exe(3332:3),TestStudio] Loader.LoadTranslatorGroups() : ------- Function End -------
[11/07 12:36:20,ArtOfTest.Runner.exe(3332:4)] First trace message from pool unnamed thread (managed ID = 4, native ID = 3180).
[11/07 12:36:20,ArtOfTest.Runner.exe(3332:4),Framework] TestAppLoader.LoadRefAssemblies() : External assembly loaded into the AppDomain: C:\Users\Automatismo\AppData\Local\Temp\Projects\8cb2c029-7312-43a6-a295-81f6268a0841\webvalenciarepo\..\webvalenciarepo\WinAPI.dll.
[11/07 12:36:20,ArtOfTest.Runner.exe(3332:4),Framework] TestAppLoader.LoadRefAssemblies() : External assembly loaded into the AppDomain: C:\Users\Automatismo\AppData\Local\Temp\Projects\8cb2c029-7312-43a6-a295-81f6268a0841\webvalenciarepo\..\webvalenciarepo\Bcn.Comun.WebTest.dll.
[11/07 12:36:20,ArtOfTest.Runner.exe(3332:4),Framework] TestAppLoader.LoadRefAssemblies() : External assembly loaded into the AppDomain: C:\Users\Automatismo\AppData\Local\Temp\Projects\8cb2c029-7312-43a6-a295-81f6268a0841\webvalenciarepo\..\webvalenciarepo\Bcn.Utils.dll.
[11/07 12:36:20,ArtOfTest.Runner.exe(3332:4),DialogPlayback] DialogMonitor.Start() : Beginning monitoring for dialogs from the set {}.
[11/07 12:36:24,ArtOfTest.Runner.exe(3332:12)] First trace message from pool unnamed thread (managed ID = 12, native ID = 4964).
[11/07 12:36:24,ArtOfTest.Runner.exe(3332:12),Framework] Manager.AddNewBrowser() : Added client ID "0683eadd-140e-431b-babc-2850eefc9ee6" (now there is/are 1 total).
[11/07 12:36:24,ArtOfTest.Runner.exe(3332:4),Execution] ExecutionEngine.InternalExecuteTest() : Executing test: 'ApoderadoValencia', path: 'ApoderadoValencia.tstest.'
[11/07 12:36:24,ArtOfTest.Runner.exe(3332:4),Execution] ExtensionsManager.LoadExtensions() : ------- Function Start -------
[11/07 12:36:24,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Got 9 plugin(s) in folder "C:\Program Files (x86)\Telerik\Test Studio\Bin\Plugins".
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "LibGit2Sharp.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Jira.BugTracking.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.OTA.Interop.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Plugins.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.Shared.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.SourceControl.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.SourceControl.Git.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.SourceControl.Git.TS.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Uncategorized] ExtensionsManager.LoadExtensions() : Loaded assembly "Telerik.TestStudio.TeamPulse.dll" from plugins folder.
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Execution] ExtensionsManager.LoadExtensions() : ------- Function End -------
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentStep() : VisualDebugger::SetCurrentStep
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Execution] ExecutionEngine.NotifyBeforeStepExecuted() : Executing step 1 "InitializeVariablesStep"...
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Execution] ExecutionEngine.NotifyAfterStepExecuted() : Finished executing step 1 "InitializeVariablesStep".
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentStep() : VisualDebugger::SetCurrentStep
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Execution] ExecutionEngine.NotifyBeforeStepExecuted() : Executing step 2 "VerificarPreCondicion"...
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Execution] ExecutionEngine.NotifyAfterStepExecuted() : Finished executing step 2 "VerificarPreCondicion".
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentStep() : VisualDebugger::SetCurrentStep
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:4),Execution] ExecutionEngine.NotifyBeforeStepExecuted() : Executing step 3 "Navigate to : 'https://sede.valencia.es/sede/'"...
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:6)] First trace message from background thread "UAI Dispatcher Thread" (managed ID = 6, native ID = 276).
[11/07 12:36:25,ArtOfTest.Runner.exe(3332:6),Uncategorized] Log.WriteLineInternal() : Unexpected dialog encountered. Closing the dialog, and halting execution.
[11/07 12:36:26,ArtOfTest.Runner.exe(3332:6),DialogPlayback] DialogMonitor.HandleUnexpectedDialog() : Unexpected dialog encountered. Closing the dialog, and halting execution.
[11/07 12:36:26,ArtOfTest.Runner.exe(3332:9)] First trace message from pool unnamed thread (managed ID = 9, native ID = 5028).
[11/07 12:36:26,ArtOfTest.Runner.exe(3332:9),Framework] Manager.RemoveBrowser() : Removed client ID "0683eadd-140e-431b-babc-2850eefc9ee6" (0 remaining).
[11/07 12:36:26,ArtOfTest.Runner.exe(3332:9),Framework] Manager.SetActiveBrowser() : Active browser is now null.
[11/07 12:36:26,ArtOfTest.Runner.exe(3332:4),Error] ExecutionEngine.CatchExecuteStepException() : EXCEPTION! (see below)
     Outer Exception Type: System.ApplicationException
     Message: Exception thrown during the wait for a condition. Error: Unexpected error while waiting on condition. Error: ArtOfTest.WebAii.Exceptions.ExecuteCommandException: ExecuteCommand failed!
          BrowserCommand (Type:'Information',Info:'IsReady',Action:'NotSet',Target:'null',Data:'',ClientId:'0683eadd-140e-431b-babc-2850eefc9ee6',HasFrames:'False',FramesInfo:'',TargetFrameIndex:'-1',InError:'False',Response:'')
          InnerException: System.InvalidOperationException: This client '0683eadd-140e-431b-babc-2850eefc9ee6' is not connected to remote to be able to process command.
          at ArtOfTest.WebAii.Core.Browser.ExecuteCommandInternal(BrowserCommand request)
          ---> System.InvalidOperationException: This client '0683eadd-140e-431b-babc-2850eefc9ee6' is not connected to remote to be able to process command.
          at ArtOfTest.WebAii.Core.Browser.ExecuteCommandInternal(BrowserCommand request)
          --- End of inner exception stack trace ---
          at ArtOfTest.WebAii.Core.Browser.CheckReadyState(Object o)
          at ArtOfTest.Common.WaitAsync._worker_DoWork[T,V](Object waitParam)
     HRESULT: 0x80131600 (Official ID (if app.) = COR_E_APPLICATION, Error Bit = FAILED, Facility = FACILITY_URT, Code = 5632)
     Call Stack:
          at ArtOfTest.Common.WaitSync.CheckResult(WaitSync wait, String extraExceptionInfo, Object target)
          at ArtOfTest.Common.WaitSync.For[T](Predicate`1 predicate, T target, Boolean invertCondition, Int32 timeout, WaitResultType errorResultType)
          at ArtOfTest.Common.WaitSync.For[T](Predicate`1 predicate, T target, Boolean invertCondition, Int32 timeout)
          at ArtOfTest.WebAii.Core.Browser.WaitUntilReady()
          at ArtOfTest.WebAii.Core.Browser.ExecuteCommand(BrowserCommand request, Boolean performDomRefresh, Boolean waitUntilReady)
          at ArtOfTest.WebAii.Core.Browser.ExecuteCommand(BrowserCommand request)
          at ArtOfTest.WebAii.Core.Browser.InternalNavigateTo(Uri uri, Boolean useDecodedUrl)
          at ArtOfTest.WebAii.Core.Browser.NavigateTo(Uri uri, Boolean useDecodedUrl)
          at ArtOfTest.WebAii.Core.Browser.NavigateTo(String url, Boolean useDecodedUrl)
          at ArtOfTest.WebAii.Design.IntrinsicTranslators.Descriptors.NavigateToActionDescriptor.Execute(Browser browser)
          at ArtOfTest.WebAii.Design.Extensibility.HtmlActionDescriptor.Execute(IAutomationHost autoHost)
          at ArtOfTest.WebAii.Design.Execution.ExecutionEngine.ExecuteStep(Int32 order)

[11/07 12:36:26,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:26,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.SetCurrentResult() : VisualDebugger::SetCurrentResult
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.ShutDown() : VisualDebbuger::ShutDown::Start
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),TestStudio] VisualDebugger.ShutDown() : VisualDebbuger::ShutDown::End
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),Framework] BrowserProvisioner.EndService() : Connecting to the provisioning pipe "Pipe.ArtOfTest.WebAii.BrowserProvisioner_-2033882765" in order to unblock and eventually terminate it...
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),Framework] BrowserProvisioner.EndService() : Provisioning pipe connected.
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:5)] First trace message from background thread "Pipe.ArtOfTest.WebAii.BrowserProvisioner" (managed ID = 5, native ID = 4700).
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:5),Framework] BrowserProvisioner.ServiceThread() : A new client has connected to the provisioning pipe but this will be treated as a termination cue.
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),Framework] BrowserProvisioner.EndService() : Provisioning thread terminated.
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),DialogPlayback] DialogMonitor.Stop() : Dialog monitoring is being halted.
[11/07 12:36:27,ArtOfTest.Runner.exe(3332:4),UIAutomation] AutomationExtensions.AddAutomationEventHandler() : Added a(n) WindowPatternIdentifiers.WindowOpenedProperty handler on element System.Windows.Automation.AutomationElement scope Descendants.
[11/07 12:36:28,Telerik.TestStudio.RemoteExecutor.exe(4780:6)] First trace message from background thread "Callback Listener Thread" (managed ID = 6, native ID = 4236).
[11/07 12:36:28,Telerik.TestStudio.RemoteExecutor.exe(4780:6),Execution] TestPlatform.AfterRunFinished() : Finished running test platform- attempting publish
[11/07 12:36:28,Telerik.TestStudio.RemoteExecutor.exe(4780:6),Framework] FireFoxInstallation.EnumFireFoxInstallations() : Valid Firefox 56.0.0.2 (x64) installation found at "C:\Program Files\Mozilla Firefox\firefox.exe".
[11/07 12:36:33,Telerik.TestStudio.ExecutionManagerService.exe(2484:14),Execution] JobRunner.<CleanupTestRunsStatus>b__19_0() : TestList finished; updating dispatch group header job Id = 4e5e0a42-e33d-4fb5-bf85-4a47b5b26389
[11/07 12:36:33,Telerik.TestStudio.ExecutionManagerService.exe(2484:14),Execution] JobRunner.<CleanupTestRunsStatus>b__19_0() : TestList finished; sending notifications
[11/07 12:37:12,Telerik.TestStudio.Scheduling.Client.exe(4644:19)] First trace message from pool unnamed thread (managed ID = 19, native ID = 4196).
[11/07 12:37:12,Telerik.TestStudio.Scheduling.Client.exe(4644:19),Framework] FireFoxInstallation.EnumFireFoxInstallations() : Valid Firefox 56.0.0.2 (x64) installation found at "C:\Program Files\Mozilla Firefox\firefox.exe".
