private void RunWarmupPass()
{
// A warmup pass is one run thru the selected scenarios and browsers.
// It allows the browsers to cache some content which helps reduce variability from run to run.
Console.WriteLine("[{0}] - Starting warmup pass -", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
foreach (string browser in _browsers)
{
using (var driver = RemoteWebDriverExtension.CreateDriverAndMaximize(browser))
{
foreach (var scenario in _scenarios)
{
Console.WriteLine("[{0}] - Warmup - Browser: {1} Scenario: {2}", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"), browser, scenario.Name);
scenario.Run(driver, browser, _logins);
Thread.Sleep(1 * 1000);
}
driver.Quit();
}
}
Console.WriteLine("[{0}] - Completed warmup pass -", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
}
// This method is the one actually responsible for executing each scenario in the workload
// It includes error checking and retry attempts as well as controls for starting and stopping ETL tracing via ElevatorServer.exe
private bool ExecuteWorkload(int iteration, string browser, string measureSetName, string wprProfileName, string tracingMode, bool overrideTimeout, bool usingTraceController, IElevatorClient elevatorClient)
{
bool passSucceeded = false;
for (int attemptNumber = 0; attemptNumber < _maxAttempts && !passSucceeded; attemptNumber++)
{
int scenarioIndex = 0;
if (attemptNumber > 0)
{
Logger.LogWriteLine(" Attempting again...");
}
string workloadName = _workloadName;
if (_enableScenarioTracing)
{
// Capturing a trace per each scenario of the workload. Append the scenario name and index to the workloadname for documentation purposes.
workloadName = _workloadName + "-0-" + _scenarios[0].ScenarioName;
}
// Start tracing
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_BROWSER} {browser} ITERATION {iteration} SCENARIO_NAME {workloadName} WPRPROFILE {wprProfileName} MODE {tracingMode}").Wait();
if (!string.IsNullOrEmpty(_executeScriptFileName))
{
// execute the selected script and pass "STARTSCENARIO"+<scenario>+<iteration>
ExecuteScript(_executeScriptFileName, $"STARTSCENARIO {_scenarios[0].ScenarioName} {iteration.ToString()}");
}
if (usingTraceController)
{
Logger.LogWriteLine($" Pausing {_e3RefreshDelaySeconds} seconds after starting the trace session to reduce interference.");
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
Logger.LogWriteLine($" Launching Browser Driver: '{browser}'");
ScenarioEventSourceProvider.EventLog.WorkloadStart(_workloadName, browser, wprProfileName, iteration, attemptNumber);
using (var driver = RemoteWebDriverExtension.CreateDriverAndMaximize(browser, _clearBrowserCache, _enableVerboseLogging, _browserProfilePath, _extensionsPaths, _port, _hostName))
{
string currentScenarioName = "";
try
{
Stopwatch watch = Stopwatch.StartNew();
bool isFirstScenario = true;
_timer.SetDriver(driver);
foreach (var currentScenario in _scenarios)
{
if (_enableScenarioTracing && scenarioIndex > 0)
{
// Capturing a trace per each scenario of the workload.
// Stop and save the current trace session which is for the last scenario.
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.END_BROWSER} {browser}").Wait();
// let's just wait a few seconds before starting the next trace
Thread.Sleep(3000);
// Append the scenario name and index to the workloadname for documentation purposes.
workloadName = _workloadName + "-" + scenarioIndex + "-" + currentScenario.ScenarioName;
// Start tracing for the current scenario
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_BROWSER} {browser} ITERATION {iteration} SCENARIO_NAME {workloadName} WPRPROFILE {wprProfileName} MODE {tracingMode}").Wait();
}
if (!string.IsNullOrEmpty(_executeScriptFileName) && scenarioIndex > 0)
{
// execute the selected script and pass "ENDSCENARIO"
ExecuteScript(_executeScriptFileName, "ENDSCENARIO");
// execute the selected script and pass "STARTSCENARIO"+<scenario>+<iteration>
ExecuteScript(_executeScriptFileName, $"STARTSCENARIO {currentScenario.ScenarioName} {iteration.ToString()}");
}
// Save the name of the current scenarion in case an exception is thrown in which case the local variable 'currentScenario' will be lost
currentScenarioName = currentScenario.ScenarioName;
_timer.SetScenario(currentScenario.ScenarioName);
// We want every scenario to take the same amount of time total, even if there are changes in
// how long pages take to load. The biggest reason for this is so that you can measure energy
// or power and their ratios will be the same either way.
// So start by getting the current time.
var startTime = watch.Elapsed;
// The first scenario naviagates in the browser's new tab / welcome page.
// After that, scenarios open in their own tabs
if (!isFirstScenario && currentScenario.Tab == "new")
{
driver.CreateNewTab();
}
isFirstScenario = false;
Logger.LogWriteLine($" Executing - Scenario: {currentScenario.ScenarioName} Iteration: {iteration} Attempt: {attemptNumber} Browser: {browser} MeasureSet: {measureSetName}");
ScenarioEventSourceProvider.EventLog.ScenarioExecutionStart(browser, currentScenario.ScenarioName);
// Here, control is handed to the scenario to navigate, and do whatever it wants
currentScenario.Scenario.Run(driver, browser, _logins, _timer);
// When we get control back, we sleep for the remaining time for the scenario. This ensures
// the total time for a scenario is always the same
var runTime = watch.Elapsed.Subtract(startTime);
var timeLeft = TimeSpan.FromSeconds(currentScenario.Duration).Subtract(runTime);
if (timeLeft < TimeSpan.FromSeconds(0) && !overrideTimeout)
{
// Of course it's possible we don't get control back until after we were supposed to
// continue to the next scenario. In that case, invalidate the run by throwing.
Logger.LogWriteLine($" !!! Scenario {currentScenario.ScenarioName} ran longer than expected! The browser ran for {runTime.TotalSeconds}s. The timeout for this scenario is {currentScenario.Duration}s.");
throw new Exception($"Scenario {currentScenario.ScenarioName} ran longer than expected! The browser ran for {runTime.TotalSeconds}s. The timeout for this scenario is {currentScenario.Duration}s.");
}
else if (!overrideTimeout)
{
ScenarioEventSourceProvider.EventLog.ScenarioIdleStart(currentScenario.ScenarioName, timeLeft.TotalSeconds);
Logger.LogWriteLine($" Scenario {currentScenario.ScenarioName} returned in {runTime.TotalSeconds} seconds. Sleep for remaining {timeLeft.TotalSeconds} seconds.");
Thread.Sleep((int)timeLeft.TotalMilliseconds);
ScenarioEventSourceProvider.EventLog.ScenarioIdleStop(currentScenario.ScenarioName, timeLeft.TotalSeconds);
}
ScenarioEventSourceProvider.EventLog.ScenarioExecutionStop(browser, currentScenario.ScenarioName);
Logger.LogWriteLine($" Completed - Scenario: {currentScenario.ScenarioName} Iteration: {iteration} Attempt: {attemptNumber} Browser: {browser} MeasureSet: {measureSetName}");
scenarioIndex++;
}
driver.CloseBrowser(browser);
passSucceeded = true;
Logger.LogWriteLine($" SUCCESS! Completed Browser: {browser} Iteration: {iteration} Attempt: {attemptNumber} MeasureSet: {measureSetName}");
ScenarioEventSourceProvider.EventLog.WorkloadStop(_workloadName, browser, wprProfileName, iteration, attemptNumber);
}
catch (Exception ex)
{
// If something goes wrong and we get an exception halfway through the scenario, we clean up
// and put everything back into a state where we can start the next iteration.
elevatorClient.SendControllerMessageAsync(Elevator.Commands.CANCEL_PASS);
if (!string.IsNullOrEmpty(_executeScriptFileName))
{
// execute the selected script and pass "FAIL"
ExecuteScript(_executeScriptFileName, "FAIL");
}
try
{
// Attempt to save the page source
string pageSourceFileName = string.Format("pageSource_{0}_{1}_{2}_{3}_{4}.html", browser, currentScenarioName, iteration, measureSetName, attemptNumber);
pageSourceFileName = Path.Combine(_etlPath, pageSourceFileName);
using (StreamWriter sw = new StreamWriter(pageSourceFileName, false))
{
sw.WriteLine(driver.PageSource);
}
// Attempt to save a screenshot
OpenQA.Selenium.Screenshot screenshot = driver.GetScreenshot();
string imageFileName = string.Format("screenshot_{0}_{1}_{2}_{3}_{4}.png", browser, currentScenarioName, iteration, measureSetName, attemptNumber);
imageFileName = Path.Combine(_etlPath, imageFileName);
screenshot.SaveAsFile(imageFileName, OpenQA.Selenium.ScreenshotImageFormat.Png);
}
catch (Exception)
{
// ignore this exception as we were just trying to see if we could get a screenshot and pagesource for the original exception.
}
driver.CloseBrowser(browser);
Logger.LogWriteLine("------ EXCEPTION caught while trying to run scenario! ------------------------------------");
Logger.LogWriteLine($" Iteration: {iteration}");
Logger.LogWriteLine($" Measure Set: {measureSetName}");
Logger.LogWriteLine($" Browser: {browser}");
Logger.LogWriteLine($" Attempt: {attemptNumber}");
Logger.LogWriteLine($" Scenario: {currentScenarioName}");
Logger.LogWriteLine($" Exception: {ex.ToString()}");
if (usingTraceController)
{
Logger.LogWriteLine(" Trace has been discarded");
}
Logger.LogWriteLine("-------------------------------------------------------");
}
finally
{
if (usingTraceController)
{
Logger.LogWriteLine($" Pausing {_e3RefreshDelaySeconds} seconds before stopping the trace session to reduce interference.");
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
}
}
}
if (passSucceeded)
{
// Stop tracing
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.END_BROWSER} {browser}").Wait();
if (!string.IsNullOrEmpty(_executeScriptFileName))
{
// execute the selected script and pass "ENDSCENARIO"
ExecuteScript(_executeScriptFileName, "ENDSCENARIO");
}
}
else
{
CleanupExtensions();
Logger.LogWriteLine($"!!! Failed to successfully complete iteration {iteration} with browser '{browser}' after {_maxAttempts} attempts!");
throw new Exception($"!!! Failed to successfully complete iteration {iteration} with browser '{browser}' after {_maxAttempts} attempts!");
}
return(passSucceeded);
}
/// <summary>
/// The main loop of the class. This method will run through the specified number of iterations on all the
/// specified browsers across all the specified scenarios.
/// </summary>
public void Run()
{
LogOsVersion();
if (_useTimer)
{
_timer.Enable();
}
if (_usingTraceController)
{
Logger.LogWriteLine("Pausing before starting first tracing session to reduce interference.");
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 going forward is from this test run and not from before running the test pass.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
using (var elevatorClient = ElevatorClient.Create(_usingTraceController))
{
elevatorClient.ConnectAsync().Wait();
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_PASS} {_etlPath}").Wait();
Logger.LogWriteLine("Starting Test Pass");
// Core Execution Loop
// TODO: Consider breaking up this large loop into smaller methods to ease readability.
for (int iteration = 0; iteration < _iterations; iteration++)
{
Logger.LogWriteLine(string.Format("Iteration: {0} ------------------", iteration));
_timer.SetIteration(iteration);
foreach (var currentMeasureSet in _measureSets)
{
if (_captureBaseline && _usingTraceController)
{
// capture a baseline of the system for this measureset
// A baseline is where we capture measureset data of the system but without running the browser and test pass.
// The idea is to get a baseline performance capture of the system without the browser and test pass so it
// can be used as a comparison.
Logger.LogWriteLine(string.Format(" Starting capture of system baseline for {0} seconds - measureset {1} iteration {2}", _baselineCaptureSeconds, currentMeasureSet.Value.Item1, iteration));
// Start the trace capture
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_BROWSER} BASE ITERATION {iteration} SCENARIO_NAME BaseLineCapture WPRPROFILE {currentMeasureSet.Value.Item1} MODE {currentMeasureSet.Value.Item2}").Wait();
Thread.Sleep(_baselineCaptureSeconds * 1000);
Logger.LogWriteLine(string.Format(" Finished capture of system baseline of measureset {0} iteration {1}", currentMeasureSet.Value.Item1, iteration));
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.END_BROWSER} BASE").Wait();
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Logger.LogWriteLine(" Pausing between tracing sessions to reduce interference.");
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
_timer.SetMeasureSet(currentMeasureSet.Key);
// Randomize the order the browsers each iteration to reduce systematic bias in the test
Random rand = new Random();
_browsers = _browsers.OrderBy(a => rand.Next()).ToList <String>();
foreach (string browser in _browsers)
{
_timer.SetBrowser(browser, _extensionsNameAndVersion);
bool passSucceeded = false;
for (int attemptNumber = 0; attemptNumber < _maxAttempts && !passSucceeded; attemptNumber++)
{
if (attemptNumber > 0)
{
Logger.LogWriteLine(" Attempting again...");
}
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_BROWSER} {browser} ITERATION {iteration} SCENARIO_NAME {_scenarioName} WPRPROFILE {currentMeasureSet.Value.Item1} MODE {currentMeasureSet.Value.Item2}").Wait();
Logger.LogWriteLine(string.Format(" Launching Browser Driver: '{0}'", browser));
ScenarioEventSourceProvider.EventLog.WorkloadStart(_scenarioName, browser, currentMeasureSet.Value.Item1, iteration, attemptNumber);
using (var driver = RemoteWebDriverExtension.CreateDriverAndMaximize(browser, _browserProfilePath, _extensionsPaths))
{
string currentScenario = "";
try
{
Stopwatch watch = Stopwatch.StartNew();
bool isFirstScenario = true;
_timer.SetDriver(driver);
foreach (var scenario in _scenarios)
{
currentScenario = scenario.ScenarioName;
_timer.SetScenario(scenario.ScenarioName);
// We want every scenario to take the same amount of time total, even if there are changes in
// how long pages take to load. The biggest reason for this is so that you can measure energy
// or power and their ratios will be the same either way.
// So start by getting the current time.
var startTime = watch.Elapsed;
// The first scenario naviagates in the browser's new tab / welcome page.
// After that, scenarios open in their own tabs
if (!isFirstScenario && scenario.Tab == "new")
{
driver.CreateNewTab();
}
else
{
isFirstScenario = false;
}
Logger.LogWriteLine(string.Format(" Executing - Scenario: {0} Iteration: {1} Attempt: {2} Browser: {3} MeasureSet: {4}", scenario.Scenario.Name, iteration, attemptNumber, browser, currentMeasureSet.Key));
ScenarioEventSourceProvider.EventLog.ScenarioExecutionStart(browser, scenario.Scenario.Name);
// Here, control is handed to the scenario to navigate, and do whatever it wants
scenario.Scenario.Run(driver, browser, _logins, _timer);
ScenarioEventSourceProvider.EventLog.ScenarioExecutionStop(browser, scenario.Scenario.Name);
// When we get control back, we sleep for the remaining time for the scenario. This ensures
// the total time for a scenario is always the same
var runTime = watch.Elapsed.Subtract(startTime);
var timeLeft = TimeSpan.FromSeconds(scenario.Duration).Subtract(runTime);
if (timeLeft < TimeSpan.FromSeconds(0) && !_overrideTimeout)
{
// Of course it's possible we don't get control back until after we were supposed to
// continue to the next scenario. In that case, invalidate the run by throwing.
Logger.LogWriteLine(string.Format(" !!! Scenario {0} ran longer than expected! The browser ran for {1}s. The timeout for this scenario is {2}s.", scenario.Scenario.Name, runTime.TotalSeconds, scenario.Duration));
throw new Exception(string.Format("Scenario {0} ran longer than expected! The browser ran for {1}s. The timeout for this scenario is {2}s.", scenario.Scenario.Name, runTime.TotalSeconds, scenario.Duration));
}
else if (!_overrideTimeout)
{
Logger.LogWriteLine(string.Format(" Scenario {0} returned in {1} seconds. Sleep for remaining {2} seconds.", scenario.Scenario.Name, runTime.TotalSeconds, timeLeft.TotalSeconds));
driver.Wait(timeLeft.TotalSeconds);
}
Logger.LogWriteLine(string.Format(" Completed - Scenario: {0} Iteration: {1} Attempt: {2} Browser: {3} MeasureSet: {4}", scenario.Scenario.Name, iteration, attemptNumber, browser, currentMeasureSet.Key, runTime.TotalSeconds));
}
driver.CloseBrowser(browser);
passSucceeded = true;
Logger.LogWriteLine(string.Format(" SUCCESS! Completed Browser: {0} Iteration: {1} Attempt: {2} MeasureSet: {3}", browser, iteration, attemptNumber, currentMeasureSet.Key));
ScenarioEventSourceProvider.EventLog.WorkloadStop(_scenarioName, browser, currentMeasureSet.Value.Item1, iteration, attemptNumber);
}
catch (Exception ex)
{
// If something goes wrong and we get an exception halfway through the scenario, we clean up
// and put everything back into a state where we can start the next iteration.
elevatorClient.SendControllerMessageAsync(Elevator.Commands.CANCEL_PASS);
try
{
// Attempt to save the page source
string pageSourceFileName = string.Format("pageSource_{0}_{1}_{2}_{3}_{4}.html", browser, currentScenario, iteration, currentMeasureSet.Key, attemptNumber);
pageSourceFileName = Path.Combine(_etlPath, pageSourceFileName);
using (StreamWriter sw = new StreamWriter(pageSourceFileName, false))
{
sw.WriteLine(driver.PageSource);
}
// Attempt to save a screenshot
OpenQA.Selenium.Screenshot screenshot = driver.GetScreenshot();
string imageFileName = string.Format("screenshot_{0}_{1}_{2}_{3}_{4}.png", browser, currentScenario, iteration, currentMeasureSet.Key, attemptNumber);
imageFileName = Path.Combine(_etlPath, imageFileName);
screenshot.SaveAsFile(imageFileName, OpenQA.Selenium.ScreenshotImageFormat.Png);
}
catch (Exception)
{
// ignore this exception as we were just trying to see if we could get a screenshot and pagesource for the original exception.
}
driver.CloseBrowser(browser);
Logger.LogWriteLine("------ EXCEPTION caught while trying to run scenario! ------------------------------------");
Logger.LogWriteLine(string.Format(" Iteration: {0}", iteration));
Logger.LogWriteLine(string.Format(" Measure Set: {0}", currentMeasureSet.Key));
Logger.LogWriteLine(string.Format(" Browser: {0}", browser));
Logger.LogWriteLine(string.Format(" Attempt: {0}", attemptNumber));
Logger.LogWriteLine(string.Format(" Scenario: {0}", currentScenario));
Logger.LogWriteLine(" Exception: " + ex.ToString());
if (_usingTraceController)
{
Logger.LogWriteLine(" Trace has been discarded");
}
Logger.LogWriteLine("-------------------------------------------------------");
}
finally
{
if (_usingTraceController)
{
Logger.LogWriteLine(" Pausing between tracing sessions to reduce interference.");
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
}
}
}
if (passSucceeded)
{
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.END_BROWSER} {browser}").Wait();
}
else
{
CleanupExtensions();
Logger.LogWriteLine(string.Format("!!! Failed to successfully complete iteration {0} with browser '{1}' after {2} attempts!", iteration, browser, _maxAttempts));
throw new Exception(string.Format("!!! Failed to successfully complete iteration {0} with browser '{1}' after {2} attempts!", iteration, browser, _maxAttempts));
}
}
}
}
CleanupExtensions();
Logger.LogWriteLine("Completed Test Pass");
elevatorClient.SendControllerMessageAsync(Elevator.Commands.END_PASS).Wait();
}
}
// This method is the one actually responsible for executing each scenario in the workload
// It includes error checking and retry attempts as well as controls for starting and stopping ETL tracing via ElevatorServer.exe
private bool ExecuteWorkload(int iteration, string browser, string measureSetName, string wprProfileName, string tracingMode, bool overrideTimeout, bool usingTraceController, IElevatorClient elevatorClient)
{
Logger.LogWriteLine(string.Format(" ExecuteWorkload for {0} seconds - measureset {1} iteration {2} wprProfileName {3} tracingMode {4}", _baselineCaptureSeconds, measureSetName, iteration, wprProfileName, tracingMode));
bool passSucceeded = false;
for (int attemptNumber = 0; attemptNumber < _maxAttempts && !passSucceeded; attemptNumber++)
{
int scenarioIndex = 0;
if (attemptNumber > 0)
{
Logger.LogWriteLine(" Attempting again...");
}
string workloadName = _workloadName;
if (_enableScenarioTracing)
{
// Capturing a trace per each scenario of the workload. Append the scenario name and index to the workloadname for documentation purposes.
workloadName = _workloadName + "-0-" + _scenarios[0].ScenarioName;
}
var workloadDuration = _pauseAfterBrowserStart;
foreach (WorkloadScenario s in _scenarios)
{
workloadDuration += s.Duration;
}
if (_enableScenarioTracing)
{
workloadDuration += _pauseBetweenScenariosRun * _scenarios.Count;
}
// Start tracing
if (_disableWpr)
{
tracingMode = "DISABLED";
}
if (!_enableScenarioTracing) // To skip tracing browser start
{
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_BROWSER} {browser} ITERATION {iteration} SCENARIO_NAME {workloadName} WPRPROFILE {wprProfileName} MODE {tracingMode} DURATION {workloadDuration + _e3RefreshDelaySeconds}").Wait();
}
if (usingTraceController)
{
Logger.LogWriteLine(string.Format(" Pausing {0} seconds after starting the trace session to reduce interference.", _e3RefreshDelaySeconds));
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
Logger.LogWriteLine(string.Format(" Launching Browser Driver: '{0}'", browser));
ScenarioEventSourceProvider.EventLog.WorkloadStart(_workloadName, browser, wprProfileName, iteration, attemptNumber);
using (var driver = RemoteWebDriverExtension.CreateDriverAndMaximize(browser, _clearBrowserCache,
_enableVerboseLogging, _browserProfilePath, _extensionsPaths, _port, _hostName,
_enableBrowserTracing, _windowMode, _broArgs))
{
Logger.LogWriteLine($" Pause {_pauseAfterBrowserStart} seconds after browser start to reduce interference");
Thread.Sleep(_pauseAfterBrowserStart * 1000);
string currentScenarioName = "";
try
{
Stopwatch watch = Stopwatch.StartNew();
bool isFirstScenario = true;
_timer.SetDriver(driver);
InfiniteLoop:
foreach (var currentScenario in _scenarios)
{
// Set up scenario environment
currentScenario.Scenario.SetUp(driver);
if (_enableScenarioTracing)
{
// Capturing a trace per each scenario of the workload.
// Stop and save the current trace session which is for the last scenario.
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.END_BROWSER} {browser}").Wait();
// let's just wait a few seconds before starting the next trace
Thread.Sleep(_pauseBetweenScenariosRun * 1000);
// Append the scenario name and index to the workloadname for documentation purposes.
workloadName = _workloadName + "-" + scenarioIndex + "-" + currentScenario.ScenarioName;
// Start tracing for the current scenario
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.START_BROWSER} {browser} ITERATION {iteration} SCENARIO_NAME {workloadName} WPRPROFILE {wprProfileName} MODE {tracingMode} DURATION {currentScenario.Duration}").Wait();
}
// Save the name of the current scenarion in case an exception is thrown in which case the local variable 'currentScenario' will be lost
currentScenarioName = currentScenario.ScenarioName;
_timer.SetScenario(currentScenario.ScenarioName);
// We want every scenario to take the same amount of time total, even if there are changes in
// how long pages take to load. The biggest reason for this is so that you can measure energy
// or power and their ratios will be the same either way.
// So start by getting the current time.
var startTime = watch.Elapsed;
// The first scenario naviagates in the browser's new tab / welcome page.
// After that, scenarios open in their own tabs
if (!isFirstScenario && currentScenario.Tab == "new")
{
driver.CreateNewTab();
}
isFirstScenario = false;
Logger.LogWriteLine(string.Format(" Executing - Scenario: {0} Iteration: {1} Attempt: {2} Browser: {3} MeasureSet: {4}", currentScenario.ScenarioName, iteration, attemptNumber, browser, measureSetName));
ScenarioEventSourceProvider.EventLog.ScenarioExecutionStart(browser, currentScenario.ScenarioName);
CancellationTokenSource ctx = null;
Task <List <OpenQA.Selenium.LogEntry> > browserTraceDumpTask = null;
// Start polling chromedriver for logs
if (_enableBrowserTracing && (browser == "chrome" || browser == "chromium" || browser == "yabro" || browser == "brodefault"))
{
if (_enableScenarioTracing)
{
RemoteWebDriverExtension.FlushChromeDriverLogs(driver); // Drop browser traces recorded before scenario run
}
ctx = new CancellationTokenSource();
browserTraceDumpTask = RemoteWebDriverExtension.GetChromeDriverLogs(driver, ctx);
}
// Here, control is handed to the scenario to navigate, and do whatever it wants
currentScenario.Scenario.Run(driver, browser, _logins, _timer);
// When we get control back, we sleep for the remaining time for the scenario. This ensures
// the total time for a scenario is always the same
var runTime = watch.Elapsed.Subtract(startTime);
var timeLeft = TimeSpan.FromSeconds(currentScenario.Duration).Subtract(runTime);
if (timeLeft < TimeSpan.FromSeconds(0) && !overrideTimeout)
{
// Of course it's possible we don't get control back until after we were supposed to
// continue to the next scenario. In that case, invalidate the run by throwing.
Logger.LogWriteLine(string.Format(" !!! Scenario {0} ran longer than expected! The browser ran for {1}s. The timeout for this scenario is {2}s.", currentScenario.ScenarioName, runTime.TotalSeconds, currentScenario.Duration));
throw new Exception(string.Format("Scenario {0} ran longer than expected! The browser ran for {1}s. The timeout for this scenario is {2}s.", currentScenario.ScenarioName, runTime.TotalSeconds, currentScenario.Duration));
}
else if (!overrideTimeout)
{
Logger.LogWriteLine(string.Format(" Scenario {0} returned in {1} seconds. Sleep for remaining {2} seconds.", currentScenario.ScenarioName, runTime.TotalSeconds, timeLeft.TotalSeconds));
driver.Wait(timeLeft.TotalSeconds, "ScenarioWait");
}
// wait same amount of seconds to avoid overlapping of tracing with Scenario TearDown
Thread.Sleep(_pauseBetweenScenariosRun * 1000);
// Tear down scenario environment
currentScenario.Scenario.TearDown(driver);
// wait for TearDown
// Thread.Sleep(_pauseBetweenScenariosRun * 1000);
// Stop polling chromedriver logs
if (ctx != null)
{
ctx.Cancel();
string browserTraceFile = Path.Combine(_etlPath, $"{browser}_{currentScenario.ScenarioName}_{iteration}_trace_DATE_DATE.json");
var browserLogs = browserTraceDumpTask.Result;
RemoteWebDriverExtension.DumpChromeDriverLogs(browserTraceFile, browserLogs);
}
SaveBenchmarkResult(currentScenario.Scenario, browser, _etlPath);
ScenarioEventSourceProvider.EventLog.ScenarioExecutionStop(browser, currentScenario.ScenarioName);
Logger.LogWriteLine(string.Format(" Completed - Scenario: {0} Iteration: {1} Attempt: {2} Browser: {3} MeasureSet: {4}", currentScenario.ScenarioName, iteration, attemptNumber, browser, measureSetName, runTime.TotalSeconds));
scenarioIndex++;
}
if (_infiniteLoop)
{
var tabs = driver.WindowHandles;
foreach (var tab in tabs)
{
if (tabs[0] != tab)
{
driver.SwitchTab(tab);
driver.Close();
}
}
driver.SwitchTab(tabs[0]);
driver.SwitchTo().DefaultContent();
goto InfiniteLoop;
}
Logger.LogWriteLine(" Wait 3s before closing browser for finishing all measurements");
Thread.Sleep(3000);
driver.CloseBrowser(browser);
passSucceeded = true;
Logger.LogWriteLine(string.Format(" SUCCESS! Completed Browser: {0} Iteration: {1} Attempt: {2} MeasureSet: {3}", browser, iteration, attemptNumber, measureSetName));
ScenarioEventSourceProvider.EventLog.WorkloadStop(_workloadName, browser, wprProfileName, iteration, attemptNumber);
}
catch (Exception ex)
{
// If something goes wrong and we get an exception halfway through the scenario, we clean up
// and put everything back into a state where we can start the next iteration.
elevatorClient.SendControllerMessageAsync(Elevator.Commands.CANCEL_PASS);
try
{
// Attempt to save the page source
string pageSourceFileName = string.Format("pageSource_{0}_{1}_{2}_{3}_{4}.html", browser, currentScenarioName, iteration, measureSetName, attemptNumber);
pageSourceFileName = Path.Combine(_etlPath, pageSourceFileName);
using (StreamWriter sw = new StreamWriter(pageSourceFileName, false))
{
sw.WriteLine(driver.PageSource);
}
// Attempt to save a screenshot
OpenQA.Selenium.Screenshot screenshot = driver.GetScreenshot();
string imageFileName = string.Format("screenshot_{0}_{1}_{2}_{3}_{4}.png", browser, currentScenarioName, iteration, measureSetName, attemptNumber);
imageFileName = Path.Combine(_etlPath, imageFileName);
screenshot.SaveAsFile(imageFileName, OpenQA.Selenium.ScreenshotImageFormat.Png);
}
catch (Exception)
{
// ignore this exception as we were just trying to see if we could get a screenshot and pagesource for the original exception.
}
driver.CloseBrowser(browser);
Logger.LogWriteLine("------ EXCEPTION caught while trying to run scenario! ------------------------------------");
Logger.LogWriteLine(string.Format(" Iteration: {0}", iteration));
Logger.LogWriteLine(string.Format(" Measure Set: {0}", measureSetName));
Logger.LogWriteLine(string.Format(" Browser: {0}", browser));
Logger.LogWriteLine(string.Format(" Attempt: {0}", attemptNumber));
Logger.LogWriteLine(string.Format(" Scenario: {0}", currentScenarioName));
Logger.LogWriteLine(" Exception: " + ex.ToString());
if (usingTraceController)
{
Logger.LogWriteLine(" Trace has been discarded");
}
Logger.LogWriteLine("-------------------------------------------------------");
}
finally
{
if (usingTraceController)
{
Logger.LogWriteLine(string.Format(" Pausing {0} seconds before stopping the trace session to reduce interference.", _e3RefreshDelaySeconds));
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
}
}
}
if (passSucceeded)
{
// Stop tracing
elevatorClient.SendControllerMessageAsync($"{Elevator.Commands.END_BROWSER} {browser}").Wait();
}
else
{
CleanupExtensions();
Logger.LogWriteLine(string.Format("!!! Failed to successfully complete iteration {0} with browser '{1}' after {2} attempts!", iteration, browser, _maxAttempts));
throw new Exception(string.Format("!!! Failed to successfully complete iteration {0} with browser '{1}' after {2} attempts!", iteration, browser, _maxAttempts));
}
return(passSucceeded);
}
/// <summary>
/// The main loop of the class. This method will run through the specified number of iterations on all the
/// specified browsers across all the specified scenarios.
/// </summary>
private void RunMainLoop()
{
if (_usingTraceController)
{
Console.WriteLine("[{0}] - Pausing before first tracing session to reduce interference.", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 going forward is from this test run and not from warmup or before running the test pass.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
Console.WriteLine("[{0}] - Starting Test Pass -", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
// Core Execution Loop
// TODO: Consider breaking up this large loop into smaller methods to ease readability.
for (int iteration = 0; iteration < _iterations; iteration++)
{
foreach (var currentMeasureSet in _measureSets)
{
// Randomize the order the browsers each iteration to reduce systematic bias in the test
Random rand = new Random();
_browsers = _browsers.OrderBy(a => rand.Next()).ToList <String>();
foreach (string browser in _browsers)
{
bool passSucceeded = false;
for (int attemptNumber = 0; attemptNumber < _maxAttempts && !passSucceeded; attemptNumber++)
{
if (attemptNumber > 0)
{
Console.WriteLine("[{0}] - Attempting again...", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
}
Console.WriteLine("[{0}] - Launching Browser Driver {1} -", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"), browser);
using (var driver = RemoteWebDriverExtension.CreateDriverAndMaximize(browser))
{
try
{
Stopwatch watch = Stopwatch.StartNew();
bool isFirstScenario = true;
foreach (var scenario in _scenarios)
{
// We want every scenario to take the same amount of time total, even if there are changes in
// how long pages take to load. The biggest reason for this is so that you can measure energy
// or power and their ratios will be the same either way.
// So start by getting the current time.
var startTime = watch.Elapsed;
// The first scenario naviagates in the browser's new tab / welcome page.
// After that, scenarios open in their own tabs
if (!isFirstScenario)
{
driver.CreateNewTab(browser);
}
else
{
isFirstScenario = false;
}
Console.WriteLine("[{0}] - Executing - Iteration: {1} Browser: {2} Scenario: {3} MeasureSet: {4}.", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"), iteration, browser, scenario.Name, currentMeasureSet.Key);
// Here, control is handed to the scenario to navigate, and do whatever it wants
scenario.Run(driver, browser, _logins);
// When we get control back, we sleep for the remaining time for the scenario. This ensures
// the total time for a scenario is always the same
var runTime = watch.Elapsed.Subtract(startTime);
var timeLeft = TimeSpan.FromSeconds(scenario.Duration).Subtract(runTime);
if (timeLeft < TimeSpan.FromSeconds(0) && !_overrideTimeout)
{
// Of course it's possible we don't get control back until after we were supposed to
// continue to the next scenario. In that case, invalidate the run by throwing.
throw new Exception(string.Format("Scenario ran longer than expected! The browser ran for {0}s. The timeout for this scenario is {1}s.", runTime.TotalSeconds, scenario.Duration));
}
else if (!_overrideTimeout)
{
Thread.Sleep(timeLeft);
}
Console.WriteLine("[{0}] - Completed - Iteration: {1} Browser: {2} Scenario: {3} MeasureSet: {4}. Scenario ran for {5} seconds.", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"), iteration, browser, scenario.Name, currentMeasureSet.Key, runTime.TotalSeconds);
}
Console.WriteLine("[{0}] - Completed Browser: {1} Iteration: {2} MeasureSet: {3}", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"), browser, iteration, currentMeasureSet.Key);
driver.CloseAllTabs(browser);
passSucceeded = true;
}
catch (Exception ex)
{
// If something goes wrong and we get an exception halfway through the scenario, we clean up
// and put everything back into a state where we can start the next iteration.
driver.CloseAllTabs(browser);
Console.WriteLine("/-EXCEPTION---------------------------------------------\\");
Console.WriteLine("[{0}] - Caught exception while trying to run scenario. Exception:", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
Console.WriteLine(ex);
if (_usingTraceController)
{
Console.WriteLine("Trace has been discarded");
}
Console.WriteLine("\\-------------------------------------------------------/");
}
finally
{
if (_usingTraceController)
{
Console.WriteLine("[{0}] - Pausing between tracing sessions to reduce interference.", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
// E3 system aggregates energy data at regular intervals. For our test passes we use 10 second intervals. Waiting here for 12 seconds before continuing ensures
// that the browser energy data reported by E3 for this run is only for this run and does not bleed into any other runs.
Thread.Sleep(_e3RefreshDelaySeconds * 1000);
}
}
}
}
}
}
}
Console.WriteLine("[{0}] - Ending Test Pass -", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss"));
}