1#!/usr/bin/env python3 2# -*- coding: utf-8 -*- 3# 4# Copyright 2014 The ChromiumOS Authors 5# Use of this source code is governed by a BSD-style license that can be 6# found in the LICENSE file. 7 8"""Tests for the experiment runner module.""" 9 10 11import getpass 12import io 13import os 14import time 15import unittest 16import unittest.mock as mock 17 18from cros_utils import command_executer 19from cros_utils.email_sender import EmailSender 20from cros_utils.file_utils import FileUtils 21from experiment_factory import ExperimentFactory 22from experiment_file import ExperimentFile 23import experiment_runner 24import experiment_status 25import machine_manager 26from results_cache import Result 27from results_report import HTMLResultsReport 28from results_report import TextResultsReport 29import test_flag 30 31import config 32 33 34EXPERIMENT_FILE_1 = """ 35 board: parrot 36 remote: chromeos-parrot1.cros chromreos-parrot2.cros 37 locks_dir: /tmp 38 39 benchmark: kraken { 40 suite: telemetry_Crosperf 41 iterations: 3 42 } 43 44 image1 { 45 chromeos_root: /usr/local/google/chromeos 46 chromeos_image: /usr/local/google/chromeos/src/build/images/parrot/latest/cros_image1.bin 47 } 48 49 image2 { 50 chromeos_image: /usr/local/google/chromeos/src/build/imaages/parrot/latest/cros_image2.bin 51 } 52 """ 53 54# pylint: disable=protected-access 55 56 57class FakeLogger(object): 58 """Fake logger for tests.""" 59 60 def __init__(self): 61 self.LogOutputCount = 0 62 self.LogErrorCount = 0 63 self.output_msgs = [] 64 self.error_msgs = [] 65 self.dot_count = 0 66 self.LogStartDotsCount = 0 67 self.LogEndDotsCount = 0 68 self.LogAppendDotCount = 0 69 70 def LogOutput(self, msg): 71 self.LogOutputCount += 1 72 self.output_msgs.append(msg) 73 74 def LogError(self, msg): 75 self.LogErrorCount += 1 76 self.error_msgs.append(msg) 77 78 def LogStartDots(self): 79 self.LogStartDotsCount += 1 80 self.dot_count += 1 81 82 def LogAppendDot(self): 83 self.LogAppendDotCount += 1 84 self.dot_count += 1 85 86 def LogEndDots(self): 87 self.LogEndDotsCount += 1 88 89 def Reset(self): 90 self.LogOutputCount = 0 91 self.LogErrorCount = 0 92 self.output_msgs = [] 93 self.error_msgs = [] 94 self.dot_count = 0 95 self.LogStartDotsCount = 0 96 self.LogEndDotsCount = 0 97 self.LogAppendDotCount = 0 98 99 100class ExperimentRunnerTest(unittest.TestCase): 101 """Test for experiment runner class.""" 102 103 run_count = 0 104 is_complete_count = 0 105 mock_logger = FakeLogger() 106 mock_cmd_exec = mock.Mock(spec=command_executer.CommandExecuter) 107 108 def make_fake_experiment(self): 109 test_flag.SetTestMode(True) 110 experiment_file = ExperimentFile(io.StringIO(EXPERIMENT_FILE_1)) 111 experiment = ExperimentFactory().GetExperiment( 112 experiment_file, working_directory="", log_dir="" 113 ) 114 return experiment 115 116 @mock.patch.object(machine_manager.MachineManager, "AddMachine") 117 @mock.patch.object(os.path, "isfile") 118 119 # pylint: disable=arguments-differ 120 def setUp(self, mock_isfile, _mock_addmachine): 121 mock_isfile.return_value = True 122 self.exp = self.make_fake_experiment() 123 124 def test_init(self): 125 er = experiment_runner.ExperimentRunner( 126 self.exp, 127 json_report=False, 128 using_schedv2=False, 129 log=self.mock_logger, 130 cmd_exec=self.mock_cmd_exec, 131 ) 132 self.assertFalse(er._terminated) 133 self.assertEqual(er.STATUS_TIME_DELAY, 10) 134 135 self.exp.log_level = "verbose" 136 er = experiment_runner.ExperimentRunner( 137 self.exp, 138 json_report=False, 139 using_schedv2=False, 140 log=self.mock_logger, 141 cmd_exec=self.mock_cmd_exec, 142 ) 143 self.assertEqual(er.STATUS_TIME_DELAY, 30) 144 145 @mock.patch.object(time, "time") 146 @mock.patch.object(time, "sleep") 147 @mock.patch.object(experiment_status.ExperimentStatus, "GetStatusString") 148 @mock.patch.object(experiment_status.ExperimentStatus, "GetProgressString") 149 def test_run( 150 self, mock_progress_string, mock_status_string, mock_sleep, mock_time 151 ): 152 153 self.run_count = 0 154 self.is_complete_count = 0 155 mock_sleep.return_value = None 156 # pylint: disable=range-builtin-not-iterating 157 mock_time.side_effect = range(1, 50, 1) 158 159 def reset(): 160 self.run_count = 0 161 self.is_complete_count = 0 162 163 def FakeRun(): 164 self.run_count += 1 165 return 0 166 167 def FakeIsComplete(): 168 self.is_complete_count += 1 169 if self.is_complete_count < 6: 170 return False 171 else: 172 return True 173 174 self.mock_logger.Reset() 175 self.exp.Run = FakeRun 176 self.exp.IsComplete = FakeIsComplete 177 178 # Test 1: log_level == "quiet" 179 self.exp.log_level = "quiet" 180 er = experiment_runner.ExperimentRunner( 181 self.exp, 182 json_report=False, 183 using_schedv2=False, 184 log=self.mock_logger, 185 cmd_exec=self.mock_cmd_exec, 186 ) 187 er.STATUS_TIME_DELAY = 2 188 mock_status_string.return_value = "Fake status string" 189 er._Run(self.exp) 190 self.assertEqual(self.run_count, 1) 191 self.assertTrue(self.is_complete_count > 0) 192 self.assertEqual(self.mock_logger.LogStartDotsCount, 1) 193 self.assertEqual(self.mock_logger.LogAppendDotCount, 1) 194 self.assertEqual(self.mock_logger.LogEndDotsCount, 1) 195 self.assertEqual(self.mock_logger.dot_count, 2) 196 self.assertEqual(mock_progress_string.call_count, 0) 197 self.assertEqual(mock_status_string.call_count, 2) 198 self.assertEqual( 199 self.mock_logger.output_msgs, 200 [ 201 "==============================", 202 "Fake status string", 203 "==============================", 204 ], 205 ) 206 self.assertEqual(len(self.mock_logger.error_msgs), 0) 207 208 # Test 2: log_level == "average" 209 self.mock_logger.Reset() 210 reset() 211 self.exp.log_level = "average" 212 mock_status_string.call_count = 0 213 er = experiment_runner.ExperimentRunner( 214 self.exp, 215 json_report=False, 216 using_schedv2=False, 217 log=self.mock_logger, 218 cmd_exec=self.mock_cmd_exec, 219 ) 220 er.STATUS_TIME_DELAY = 2 221 mock_status_string.return_value = "Fake status string" 222 er._Run(self.exp) 223 self.assertEqual(self.run_count, 1) 224 self.assertTrue(self.is_complete_count > 0) 225 self.assertEqual(self.mock_logger.LogStartDotsCount, 1) 226 self.assertEqual(self.mock_logger.LogAppendDotCount, 1) 227 self.assertEqual(self.mock_logger.LogEndDotsCount, 1) 228 self.assertEqual(self.mock_logger.dot_count, 2) 229 self.assertEqual(mock_progress_string.call_count, 0) 230 self.assertEqual(mock_status_string.call_count, 2) 231 self.assertEqual( 232 self.mock_logger.output_msgs, 233 [ 234 "==============================", 235 "Fake status string", 236 "==============================", 237 ], 238 ) 239 self.assertEqual(len(self.mock_logger.error_msgs), 0) 240 241 # Test 3: log_level == "verbose" 242 self.mock_logger.Reset() 243 reset() 244 self.exp.log_level = "verbose" 245 mock_status_string.call_count = 0 246 er = experiment_runner.ExperimentRunner( 247 self.exp, 248 json_report=False, 249 using_schedv2=False, 250 log=self.mock_logger, 251 cmd_exec=self.mock_cmd_exec, 252 ) 253 er.STATUS_TIME_DELAY = 2 254 mock_status_string.return_value = "Fake status string" 255 mock_progress_string.return_value = "Fake progress string" 256 er._Run(self.exp) 257 self.assertEqual(self.run_count, 1) 258 self.assertTrue(self.is_complete_count > 0) 259 self.assertEqual(self.mock_logger.LogStartDotsCount, 0) 260 self.assertEqual(self.mock_logger.LogAppendDotCount, 0) 261 self.assertEqual(self.mock_logger.LogEndDotsCount, 0) 262 self.assertEqual(self.mock_logger.dot_count, 0) 263 self.assertEqual(mock_progress_string.call_count, 2) 264 self.assertEqual(mock_status_string.call_count, 2) 265 self.assertEqual( 266 self.mock_logger.output_msgs, 267 [ 268 "==============================", 269 "Fake progress string", 270 "Fake status string", 271 "==============================", 272 "==============================", 273 "Fake progress string", 274 "Fake status string", 275 "==============================", 276 ], 277 ) 278 self.assertEqual(len(self.mock_logger.error_msgs), 0) 279 280 @mock.patch.object(TextResultsReport, "GetReport") 281 def test_print_table(self, mock_report): 282 self.mock_logger.Reset() 283 mock_report.return_value = "This is a fake experiment report." 284 er = experiment_runner.ExperimentRunner( 285 self.exp, 286 json_report=False, 287 using_schedv2=False, 288 log=self.mock_logger, 289 cmd_exec=self.mock_cmd_exec, 290 ) 291 er._PrintTable(self.exp) 292 self.assertEqual(mock_report.call_count, 1) 293 self.assertEqual( 294 self.mock_logger.output_msgs, ["This is a fake experiment report."] 295 ) 296 297 @mock.patch.object(HTMLResultsReport, "GetReport") 298 @mock.patch.object(TextResultsReport, "GetReport") 299 @mock.patch.object(EmailSender, "Attachment") 300 @mock.patch.object(EmailSender, "SendEmail") 301 @mock.patch.object(getpass, "getuser") 302 def test_email( 303 self, 304 mock_getuser, 305 mock_emailer, 306 mock_attachment, 307 mock_text_report, 308 mock_html_report, 309 ): 310 311 mock_getuser.return_value = "[email protected]" 312 mock_text_report.return_value = "This is a fake text report." 313 mock_html_report.return_value = "This is a fake html report." 314 315 self.mock_logger.Reset() 316 config.AddConfig("no_email", True) 317 self.exp.email_to = ["[email protected]"] 318 er = experiment_runner.ExperimentRunner( 319 self.exp, 320 json_report=False, 321 using_schedv2=False, 322 log=self.mock_logger, 323 cmd_exec=self.mock_cmd_exec, 324 ) 325 # Test 1. Config:no_email; exp.email_to set ==> no email sent 326 er._Email(self.exp) 327 self.assertEqual(mock_getuser.call_count, 0) 328 self.assertEqual(mock_emailer.call_count, 0) 329 self.assertEqual(mock_attachment.call_count, 0) 330 self.assertEqual(mock_text_report.call_count, 0) 331 self.assertEqual(mock_html_report.call_count, 0) 332 333 # Test 2. Config: email. exp.email_to set; cache hit. => send email 334 self.mock_logger.Reset() 335 config.AddConfig("no_email", False) 336 for r in self.exp.benchmark_runs: 337 r.cache_hit = True 338 er._Email(self.exp) 339 self.assertEqual(mock_getuser.call_count, 1) 340 self.assertEqual(mock_emailer.call_count, 1) 341 self.assertEqual(mock_attachment.call_count, 1) 342 self.assertEqual(mock_text_report.call_count, 1) 343 self.assertEqual(mock_html_report.call_count, 1) 344 self.assertEqual(len(mock_emailer.call_args), 2) 345 self.assertEqual( 346 mock_emailer.call_args[0], 347 ( 348 ["[email protected]", "[email protected]"], 349 ": image1 vs. image2", 350 "<pre style='font-size: 13px'>This is a fake text " 351 "report.\nResults are stored in _results.\n</pre>", 352 ), 353 ) 354 self.assertTrue(isinstance(mock_emailer.call_args[1], dict)) 355 self.assertEqual(len(mock_emailer.call_args[1]), 2) 356 self.assertTrue("attachments" in mock_emailer.call_args[1].keys()) 357 self.assertEqual(mock_emailer.call_args[1]["msg_type"], "html") 358 359 mock_attachment.assert_called_with( 360 "report.html", "This is a fake html report." 361 ) 362 363 # Test 3. Config: email; exp.mail_to set; no cache hit. => send email 364 self.mock_logger.Reset() 365 mock_getuser.reset_mock() 366 mock_emailer.reset_mock() 367 mock_attachment.reset_mock() 368 mock_text_report.reset_mock() 369 mock_html_report.reset_mock() 370 config.AddConfig("no_email", False) 371 for r in self.exp.benchmark_runs: 372 r.cache_hit = False 373 er._Email(self.exp) 374 self.assertEqual(mock_getuser.call_count, 1) 375 self.assertEqual(mock_emailer.call_count, 1) 376 self.assertEqual(mock_attachment.call_count, 1) 377 self.assertEqual(mock_text_report.call_count, 1) 378 self.assertEqual(mock_html_report.call_count, 1) 379 self.assertEqual(len(mock_emailer.call_args), 2) 380 self.assertEqual( 381 mock_emailer.call_args[0], 382 ( 383 [ 384 "[email protected]", 385 "[email protected]", 386 "[email protected]", 387 ], 388 ": image1 vs. image2", 389 "<pre style='font-size: 13px'>This is a fake text " 390 "report.\nResults are stored in _results.\n</pre>", 391 ), 392 ) 393 self.assertTrue(isinstance(mock_emailer.call_args[1], dict)) 394 self.assertEqual(len(mock_emailer.call_args[1]), 2) 395 self.assertTrue("attachments" in mock_emailer.call_args[1].keys()) 396 self.assertEqual(mock_emailer.call_args[1]["msg_type"], "html") 397 398 mock_attachment.assert_called_with( 399 "report.html", "This is a fake html report." 400 ) 401 402 # Test 4. Config: email; exp.mail_to = None; no cache hit. => send email 403 self.mock_logger.Reset() 404 mock_getuser.reset_mock() 405 mock_emailer.reset_mock() 406 mock_attachment.reset_mock() 407 mock_text_report.reset_mock() 408 mock_html_report.reset_mock() 409 self.exp.email_to = [] 410 er._Email(self.exp) 411 self.assertEqual(mock_getuser.call_count, 1) 412 self.assertEqual(mock_emailer.call_count, 1) 413 self.assertEqual(mock_attachment.call_count, 1) 414 self.assertEqual(mock_text_report.call_count, 1) 415 self.assertEqual(mock_html_report.call_count, 1) 416 self.assertEqual(len(mock_emailer.call_args), 2) 417 self.assertEqual( 418 mock_emailer.call_args[0], 419 ( 420 ["[email protected]"], 421 ": image1 vs. image2", 422 "<pre style='font-size: 13px'>This is a fake text " 423 "report.\nResults are stored in _results.\n</pre>", 424 ), 425 ) 426 self.assertTrue(isinstance(mock_emailer.call_args[1], dict)) 427 self.assertEqual(len(mock_emailer.call_args[1]), 2) 428 self.assertTrue("attachments" in mock_emailer.call_args[1].keys()) 429 self.assertEqual(mock_emailer.call_args[1]["msg_type"], "html") 430 431 mock_attachment.assert_called_with( 432 "report.html", "This is a fake html report." 433 ) 434 435 # Test 5. Config: email; exp.mail_to = None; cache hit => no email sent 436 self.mock_logger.Reset() 437 mock_getuser.reset_mock() 438 mock_emailer.reset_mock() 439 mock_attachment.reset_mock() 440 mock_text_report.reset_mock() 441 mock_html_report.reset_mock() 442 for r in self.exp.benchmark_runs: 443 r.cache_hit = True 444 er._Email(self.exp) 445 self.assertEqual(mock_getuser.call_count, 0) 446 self.assertEqual(mock_emailer.call_count, 0) 447 self.assertEqual(mock_attachment.call_count, 0) 448 self.assertEqual(mock_text_report.call_count, 0) 449 self.assertEqual(mock_html_report.call_count, 0) 450 451 @mock.patch.object(FileUtils, "RmDir") 452 @mock.patch.object(FileUtils, "MkDirP") 453 @mock.patch.object(FileUtils, "WriteFile") 454 @mock.patch.object(HTMLResultsReport, "FromExperiment") 455 @mock.patch.object(TextResultsReport, "FromExperiment") 456 @mock.patch.object(Result, "CompressResultsTo") 457 @mock.patch.object(Result, "CopyResultsTo") 458 @mock.patch.object(Result, "CleanUp") 459 @mock.patch.object(Result, "FormatStringTopCommands") 460 @mock.patch("builtins.open", new_callable=mock.mock_open) 461 def test_store_results( 462 self, 463 mock_open, 464 mock_top_commands, 465 mock_cleanup, 466 mock_copy, 467 mock_compress, 468 _mock_text_report, 469 mock_report, 470 mock_writefile, 471 mock_mkdir, 472 mock_rmdir, 473 ): 474 475 self.mock_logger.Reset() 476 self.exp.results_directory = "/usr/local/crosperf-results" 477 bench_run = self.exp.benchmark_runs[5] 478 bench_path = "/usr/local/crosperf-results/" + "".join( 479 ch for ch in bench_run.name if ch.isalnum() 480 ) 481 self.assertEqual(len(self.exp.benchmark_runs), 6) 482 483 er = experiment_runner.ExperimentRunner( 484 self.exp, 485 json_report=False, 486 using_schedv2=False, 487 log=self.mock_logger, 488 cmd_exec=self.mock_cmd_exec, 489 ) 490 491 # Test 1. Make sure nothing is done if _terminated is true. 492 er._terminated = True 493 er._StoreResults(self.exp) 494 self.assertEqual(mock_cleanup.call_count, 0) 495 self.assertEqual(mock_copy.call_count, 0) 496 self.assertEqual(mock_compress.call_count, 0) 497 self.assertEqual(mock_report.call_count, 0) 498 self.assertEqual(mock_writefile.call_count, 0) 499 self.assertEqual(mock_mkdir.call_count, 0) 500 self.assertEqual(mock_rmdir.call_count, 0) 501 self.assertEqual(self.mock_logger.LogOutputCount, 0) 502 self.assertEqual(mock_open.call_count, 0) 503 self.assertEqual(mock_top_commands.call_count, 0) 504 505 # Test 2. _terminated is false; everything works properly. 506 fake_result = Result( 507 self.mock_logger, self.exp.labels[0], "average", "daisy1" 508 ) 509 for r in self.exp.benchmark_runs: 510 r.result = fake_result 511 er._terminated = False 512 self.exp.compress_results = False 513 er._StoreResults(self.exp) 514 self.assertEqual(mock_cleanup.call_count, 6) 515 mock_cleanup.assert_called_with(bench_run.benchmark.rm_chroot_tmp) 516 self.assertEqual(mock_copy.call_count, 6) 517 mock_copy.assert_called_with(bench_path) 518 self.assertEqual(mock_writefile.call_count, 3) 519 self.assertEqual(len(mock_writefile.call_args_list), 3) 520 first_args = mock_writefile.call_args_list[0] 521 second_args = mock_writefile.call_args_list[1] 522 self.assertEqual( 523 first_args[0][0], "/usr/local/crosperf-results/experiment.exp" 524 ) 525 self.assertEqual( 526 second_args[0][0], "/usr/local/crosperf-results/results.html" 527 ) 528 self.assertEqual(mock_mkdir.call_count, 1) 529 mock_mkdir.assert_called_with("/usr/local/crosperf-results") 530 self.assertEqual(mock_rmdir.call_count, 1) 531 mock_rmdir.assert_called_with("/usr/local/crosperf-results") 532 self.assertEqual(self.mock_logger.LogOutputCount, 5) 533 self.assertEqual( 534 self.mock_logger.output_msgs, 535 [ 536 "Storing experiment file in /usr/local/crosperf-results.", 537 "Storing top statistics of each benchmark run into" 538 " /usr/local/crosperf-results/topstats.log.", 539 "Storing results of each benchmark run.", 540 "Storing results report in /usr/local/crosperf-results.", 541 "Storing email message body in /usr/local/crosperf-results.", 542 ], 543 ) 544 self.assertEqual(mock_open.call_count, 1) 545 # Check write to a topstats.log file. 546 mock_open.assert_called_with( 547 "/usr/local/crosperf-results/topstats.log", "w" 548 ) 549 mock_open().write.assert_called() 550 551 # Check top calls with no arguments. 552 topcalls = [mock.call()] * 6 553 self.assertEqual(mock_top_commands.call_args_list, topcalls) 554 555 # Test 3. Test compress_results. 556 self.exp.compress_results = True 557 mock_copy.call_count = 0 558 mock_compress.call_count = 0 559 er._StoreResults(self.exp) 560 self.assertEqual(mock_copy.call_count, 0) 561 mock_copy.assert_called_with(bench_path) 562 self.assertEqual(mock_compress.call_count, 6) 563 mock_compress.assert_called_with(bench_path) 564 565 566if __name__ == "__main__": 567 unittest.main() 568