experiment_runner_unittest.py revision 9959b1eb9166ed81840c7e08ff179f00a5448cf2 
1#!/usr/bin/python
2#
3# Copyright 2014 Google Inc. All Rights Reserved
4import StringIO
5import getpass
6import os
7
8import mock
9import unittest
10
11import experiment_runner
12import experiment_status
13import machine_manager
14import config
15import test_flag
16from experiment_file import ExperimentFile
17from experiment_factory import ExperimentFactory
18from results_report import TextResultsReport
19from results_report import HTMLResultsReport
20from results_cache import Result
21
22from cros_utils import command_executer
23from cros_utils.email_sender import EmailSender
24from cros_utils.file_utils import FileUtils
25
26EXPERIMENT_FILE_1 = """
27  board: parrot
28  remote: chromeos-parrot1.cros chromreos-parrot2.cros
29
30  benchmark: kraken {
31    suite: telemetry_Crosperf
32    iterations: 3
33  }
34
35  image1 {
36    chromeos_root: /usr/local/google/chromeos
37    chromeos_image: /usr/local/google/chromeos/src/build/images/parrot/latest/cros_image1.bin
38  }
39
40  image2 {
41    chromeos_image: /usr/local/google/chromeos/src/build/imaages/parrot/latest/cros_image2.bin
42  }
43  """
44
45
46class FakeLogger(object):
47
48  def __init__(self):
49    self.LogOutputCount = 0
50    self.LogErrorCount = 0
51    self.output_msgs = []
52    self.error_msgs = []
53    self.dot_count = 0
54    self.LogStartDotsCount = 0
55    self.LogEndDotsCount = 0
56    self.LogAppendDotCount = 0
57
58  def LogOutput(self, msg):
59    self.LogOutputCount += 1
60    self.output_msgs.append(msg)
61
62  def LogError(self, msg):
63    self.LogErrorCount += 1
64    self.error_msgs.append(msg)
65
66  def LogStartDots(self):
67    self.LogStartDotsCount += 1
68    self.dot_count += 1
69
70  def LogAppendDot(self):
71    self.LogAppendDotCount += 1
72    self.dot_count += 1
73
74  def LogEndDots(self):
75    self.LogEndDotsCount += 1
76
77  def Reset(self):
78    self.LogOutputCount = 0
79    self.LogErrorCount = 0
80    self.output_msgs = []
81    self.error_msgs = []
82    self.dot_count = 0
83    self.LogStartDotsCount = 0
84    self.LogEndDotsCount = 0
85    self.LogAppendDotCount = 0
86
87
88class ExperimentRunnerTest(unittest.TestCase):
89
90  run_counter = 0
91  mock_logger = FakeLogger()
92  mock_cmd_exec = mock.Mock(spec=command_executer.CommandExecuter)
93
94  def make_fake_experiment(self):
95    test_flag.SetTestMode(True)
96    experiment_file = ExperimentFile(StringIO.StringIO(EXPERIMENT_FILE_1))
97    experiment = ExperimentFactory().GetExperiment(experiment_file,
98                                                   working_directory='',
99                                                   log_dir='')
100    return experiment
101
102  @mock.patch.object(machine_manager.MachineManager, 'AddMachine')
103  @mock.patch.object(os.path, 'isfile')
104  def setUp(self, mock_isfile, mock_addmachine):
105    mock_isfile.return_value = True
106    self.exp = self.make_fake_experiment()
107
108  def test_init(self):
109    er = experiment_runner.ExperimentRunner(self.exp,
110                                            json_report=False,
111                                            using_schedv2=False,
112                                            log=self.mock_logger,
113                                            cmd_exec=self.mock_cmd_exec)
114    self.assertFalse(er._terminated)
115    self.assertEqual(er.STATUS_TIME_DELAY, 10)
116
117    self.exp.log_level = 'verbose'
118    er = experiment_runner.ExperimentRunner(self.exp,
119                                            json_report=False,
120                                            using_schedv2=False,
121                                            log=self.mock_logger,
122                                            cmd_exec=self.mock_cmd_exec)
123    self.assertEqual(er.STATUS_TIME_DELAY, 30)
124
125  @mock.patch.object(experiment_status.ExperimentStatus, 'GetStatusString')
126  @mock.patch.object(experiment_status.ExperimentStatus, 'GetProgressString')
127  def test_run(self, mock_progress_string, mock_status_string):
128
129    self.run_count = 0
130    self.is_complete_count = 0
131
132    def reset():
133      self.run_count = 0
134      self.is_complete_count = 0
135
136    def FakeRun():
137      self.run_count += 1
138      return 0
139
140    def FakeIsComplete():
141      self.is_complete_count += 1
142      if self.is_complete_count < 3:
143        return False
144      else:
145        return True
146
147    self.mock_logger.Reset()
148    self.exp.Run = FakeRun
149    self.exp.IsComplete = FakeIsComplete
150
151    # Test 1: log_level == "quiet"
152    self.exp.log_level = 'quiet'
153    er = experiment_runner.ExperimentRunner(self.exp,
154                                            json_report=False,
155                                            using_schedv2=False,
156                                            log=self.mock_logger,
157                                            cmd_exec=self.mock_cmd_exec)
158    er.STATUS_TIME_DELAY = 2
159    mock_status_string.return_value = 'Fake status string'
160    er._Run(self.exp)
161    self.assertEqual(self.run_count, 1)
162    self.assertTrue(self.is_complete_count > 0)
163    self.assertEqual(self.mock_logger.LogStartDotsCount, 1)
164    self.assertEqual(self.mock_logger.LogAppendDotCount, 1)
165    self.assertEqual(self.mock_logger.LogEndDotsCount, 1)
166    self.assertEqual(self.mock_logger.dot_count, 2)
167    self.assertEqual(mock_progress_string.call_count, 0)
168    self.assertEqual(mock_status_string.call_count, 2)
169    self.assertEqual(self.mock_logger.output_msgs,
170                     ['==============================', 'Fake status string',
171                      '=============================='])
172    self.assertEqual(len(self.mock_logger.error_msgs), 0)
173
174    # Test 2: log_level == "average"
175    self.mock_logger.Reset()
176    reset()
177    self.exp.log_level = 'average'
178    mock_status_string.call_count = 0
179    er = experiment_runner.ExperimentRunner(self.exp,
180                                            json_report=False,
181                                            using_schedv2=False,
182                                            log=self.mock_logger,
183                                            cmd_exec=self.mock_cmd_exec)
184    er.STATUS_TIME_DELAY = 2
185    mock_status_string.return_value = 'Fake status string'
186    er._Run(self.exp)
187    self.assertEqual(self.run_count, 1)
188    self.assertTrue(self.is_complete_count > 0)
189    self.assertEqual(self.mock_logger.LogStartDotsCount, 1)
190    self.assertEqual(self.mock_logger.LogAppendDotCount, 1)
191    self.assertEqual(self.mock_logger.LogEndDotsCount, 1)
192    self.assertEqual(self.mock_logger.dot_count, 2)
193    self.assertEqual(mock_progress_string.call_count, 0)
194    self.assertEqual(mock_status_string.call_count, 2)
195    self.assertEqual(self.mock_logger.output_msgs,
196                     ['==============================', 'Fake status string',
197                      '=============================='])
198    self.assertEqual(len(self.mock_logger.error_msgs), 0)
199
200    # Test 3: log_level == "verbose"
201    self.mock_logger.Reset()
202    reset()
203    self.exp.log_level = 'verbose'
204    mock_status_string.call_count = 0
205    er = experiment_runner.ExperimentRunner(self.exp,
206                                            json_report=False,
207                                            using_schedv2=False,
208                                            log=self.mock_logger,
209                                            cmd_exec=self.mock_cmd_exec)
210    er.STATUS_TIME_DELAY = 2
211    mock_status_string.return_value = 'Fake status string'
212    mock_progress_string.return_value = 'Fake progress string'
213    er._Run(self.exp)
214    self.assertEqual(self.run_count, 1)
215    self.assertTrue(self.is_complete_count > 0)
216    self.assertEqual(self.mock_logger.LogStartDotsCount, 0)
217    self.assertEqual(self.mock_logger.LogAppendDotCount, 0)
218    self.assertEqual(self.mock_logger.LogEndDotsCount, 0)
219    self.assertEqual(self.mock_logger.dot_count, 0)
220    self.assertEqual(mock_progress_string.call_count, 2)
221    self.assertEqual(mock_status_string.call_count, 2)
222    self.assertEqual(self.mock_logger.output_msgs,
223                     ['==============================', 'Fake progress string',
224                      'Fake status string', '==============================',
225                      '==============================', 'Fake progress string',
226                      'Fake status string', '=============================='])
227    self.assertEqual(len(self.mock_logger.error_msgs), 0)
228
229  @mock.patch.object(TextResultsReport, 'GetReport')
230  def test_print_table(self, mock_report):
231    self.mock_logger.Reset()
232    mock_report.return_value = 'This is a fake experiment report.'
233    er = experiment_runner.ExperimentRunner(self.exp,
234                                            json_report=False,
235                                            using_schedv2=False,
236                                            log=self.mock_logger,
237                                            cmd_exec=self.mock_cmd_exec)
238    er._PrintTable(self.exp)
239    self.assertEqual(mock_report.call_count, 1)
240    self.assertEqual(self.mock_logger.output_msgs,
241                     ['This is a fake experiment report.'])
242
243  @mock.patch.object(HTMLResultsReport, 'GetReport')
244  @mock.patch.object(TextResultsReport, 'GetReport')
245  @mock.patch.object(EmailSender, 'Attachment')
246  @mock.patch.object(EmailSender, 'SendEmail')
247  @mock.patch.object(getpass, 'getuser')
248  def test_email(self, mock_getuser, mock_emailer, mock_attachment,
249                 mock_text_report, mock_html_report):
250
251    mock_getuser.return_value = 'john.smith@google.com'
252    mock_text_report.return_value = 'This is a fake text report.'
253    mock_html_report.return_value = 'This is a fake html report.'
254
255    self.mock_logger.Reset()
256    config.AddConfig('no_email', True)
257    self.exp.email_to = ['jane.doe@google.com']
258    er = experiment_runner.ExperimentRunner(self.exp,
259                                            json_report=False,
260                                            using_schedv2=False,
261                                            log=self.mock_logger,
262                                            cmd_exec=self.mock_cmd_exec)
263    # Test 1. Config:no_email; exp.email_to set ==> no email sent
264    er._Email(self.exp)
265    self.assertEqual(mock_getuser.call_count, 0)
266    self.assertEqual(mock_emailer.call_count, 0)
267    self.assertEqual(mock_attachment.call_count, 0)
268    self.assertEqual(mock_text_report.call_count, 0)
269    self.assertEqual(mock_html_report.call_count, 0)
270
271    # Test 2. Config: email. exp.email_to set; cache hit.  => send email
272    self.mock_logger.Reset()
273    config.AddConfig('no_email', False)
274    for r in self.exp.benchmark_runs:
275      r.cache_hit = True
276    er._Email(self.exp)
277    self.assertEqual(mock_getuser.call_count, 1)
278    self.assertEqual(mock_emailer.call_count, 1)
279    self.assertEqual(mock_attachment.call_count, 1)
280    self.assertEqual(mock_text_report.call_count, 1)
281    self.assertEqual(mock_html_report.call_count, 1)
282    self.assertEqual(len(mock_emailer.call_args), 2)
283    self.assertEqual(mock_emailer.call_args[0],
284                     (['jane.doe@google.com', 'john.smith@google.com'],
285                      ': image1 vs. image2',
286                      "<pre style='font-size: 13px'>This is a fake text "
287                      'report.\nResults are stored in _results.\n</pre>'))
288    self.assertTrue(type(mock_emailer.call_args[1]) is dict)
289    self.assertEqual(len(mock_emailer.call_args[1]), 2)
290    self.assertTrue('attachments' in mock_emailer.call_args[1].keys())
291    self.assertEqual(mock_emailer.call_args[1]['msg_type'], 'html')
292
293    mock_attachment.assert_called_with('report.html',
294                                       'This is a fake html report.')
295
296    # Test 3. Config: email; exp.mail_to set; no cache hit.  => send email
297    self.mock_logger.Reset()
298    mock_getuser.reset_mock()
299    mock_emailer.reset_mock()
300    mock_attachment.reset_mock()
301    mock_text_report.reset_mock()
302    mock_html_report.reset_mock()
303    config.AddConfig('no_email', False)
304    for r in self.exp.benchmark_runs:
305      r.cache_hit = False
306    er._Email(self.exp)
307    self.assertEqual(mock_getuser.call_count, 1)
308    self.assertEqual(mock_emailer.call_count, 1)
309    self.assertEqual(mock_attachment.call_count, 1)
310    self.assertEqual(mock_text_report.call_count, 1)
311    self.assertEqual(mock_html_report.call_count, 1)
312    self.assertEqual(len(mock_emailer.call_args), 2)
313    self.assertEqual(mock_emailer.call_args[0],
314                     (['jane.doe@google.com', 'john.smith@google.com',
315                       'john.smith@google.com'],
316                      ': image1 vs. image2',
317                      "<pre style='font-size: 13px'>This is a fake text "
318                      'report.\nResults are stored in _results.\n</pre>'))
319    self.assertTrue(type(mock_emailer.call_args[1]) is dict)
320    self.assertEqual(len(mock_emailer.call_args[1]), 2)
321    self.assertTrue('attachments' in mock_emailer.call_args[1].keys())
322    self.assertEqual(mock_emailer.call_args[1]['msg_type'], 'html')
323
324    mock_attachment.assert_called_with('report.html',
325                                       'This is a fake html report.')
326
327    # Test 4. Config: email; exp.mail_to = None; no cache hit. => send email
328    self.mock_logger.Reset()
329    mock_getuser.reset_mock()
330    mock_emailer.reset_mock()
331    mock_attachment.reset_mock()
332    mock_text_report.reset_mock()
333    mock_html_report.reset_mock()
334    self.exp.email_to = []
335    er._Email(self.exp)
336    self.assertEqual(mock_getuser.call_count, 1)
337    self.assertEqual(mock_emailer.call_count, 1)
338    self.assertEqual(mock_attachment.call_count, 1)
339    self.assertEqual(mock_text_report.call_count, 1)
340    self.assertEqual(mock_html_report.call_count, 1)
341    self.assertEqual(len(mock_emailer.call_args), 2)
342    self.assertEqual(mock_emailer.call_args[0],
343                     (['john.smith@google.com'], ': image1 vs. image2',
344                      "<pre style='font-size: 13px'>This is a fake text "
345                      'report.\nResults are stored in _results.\n</pre>'))
346    self.assertTrue(type(mock_emailer.call_args[1]) is dict)
347    self.assertEqual(len(mock_emailer.call_args[1]), 2)
348    self.assertTrue('attachments' in mock_emailer.call_args[1].keys())
349    self.assertEqual(mock_emailer.call_args[1]['msg_type'], 'html')
350
351    mock_attachment.assert_called_with('report.html',
352                                       'This is a fake html report.')
353
354    # Test 5. Config: email; exp.mail_to = None; cache hit => no email sent
355    self.mock_logger.Reset()
356    mock_getuser.reset_mock()
357    mock_emailer.reset_mock()
358    mock_attachment.reset_mock()
359    mock_text_report.reset_mock()
360    mock_html_report.reset_mock()
361    for r in self.exp.benchmark_runs:
362      r.cache_hit = True
363    er._Email(self.exp)
364    self.assertEqual(mock_getuser.call_count, 0)
365    self.assertEqual(mock_emailer.call_count, 0)
366    self.assertEqual(mock_attachment.call_count, 0)
367    self.assertEqual(mock_text_report.call_count, 0)
368    self.assertEqual(mock_html_report.call_count, 0)
369
370  @mock.patch.object(FileUtils, 'RmDir')
371  @mock.patch.object(FileUtils, 'MkDirP')
372  @mock.patch.object(FileUtils, 'WriteFile')
373  @mock.patch.object(HTMLResultsReport, 'GetReport')
374  @mock.patch.object(TextResultsReport, 'GetReport')
375  @mock.patch.object(Result, 'CopyResultsTo')
376  @mock.patch.object(Result, 'CleanUp')
377  def test_store_results(self, mock_cleanup, mock_copy, mock_text_report,
378                         mock_report, mock_writefile, mock_mkdir, mock_rmdir):
379
380    self.mock_logger.Reset()
381    self.exp.results_directory = '/usr/local/crosperf-results'
382    bench_run = self.exp.benchmark_runs[5]
383    bench_path = '/usr/local/crosperf-results/' + filter(str.isalnum,
384                                                         bench_run.name)
385    self.assertEqual(len(self.exp.benchmark_runs), 6)
386
387    er = experiment_runner.ExperimentRunner(self.exp,
388                                            json_report=False,
389                                            using_schedv2=False,
390                                            log=self.mock_logger,
391                                            cmd_exec=self.mock_cmd_exec)
392
393    # Test 1. Make sure nothing is done if _terminated is true.
394    er._terminated = True
395    er._StoreResults(self.exp)
396    self.assertEqual(mock_cleanup.call_count, 0)
397    self.assertEqual(mock_copy.call_count, 0)
398    self.assertEqual(mock_report.call_count, 0)
399    self.assertEqual(mock_writefile.call_count, 0)
400    self.assertEqual(mock_mkdir.call_count, 0)
401    self.assertEqual(mock_rmdir.call_count, 0)
402    self.assertEqual(self.mock_logger.LogOutputCount, 0)
403
404    # Test 2. _terminated is false; everything works properly.
405    fake_result = Result(self.mock_logger, self.exp.labels[0], 'average',
406                         'daisy1')
407    for r in self.exp.benchmark_runs:
408      r.result = fake_result
409    er._terminated = False
410    er._StoreResults(self.exp)
411    self.assertEqual(mock_cleanup.call_count, 6)
412    mock_cleanup.called_with(bench_run.benchmark.rm_chroot_tmp)
413    self.assertEqual(mock_copy.call_count, 6)
414    mock_copy.called_with(bench_path)
415    self.assertEqual(mock_writefile.call_count, 3)
416    self.assertEqual(len(mock_writefile.call_args_list), 3)
417    first_args = mock_writefile.call_args_list[0]
418    second_args = mock_writefile.call_args_list[1]
419    self.assertEqual(first_args[0][0],
420                     '/usr/local/crosperf-results/experiment.exp')
421    self.assertEqual(second_args[0][0],
422                     '/usr/local/crosperf-results/results.html')
423    self.assertEqual(mock_mkdir.call_count, 1)
424    mock_mkdir.called_with('/usr/local/crosperf-results')
425    self.assertEqual(mock_rmdir.call_count, 1)
426    mock_rmdir.called_with('/usr/local/crosperf-results')
427    self.assertEqual(self.mock_logger.LogOutputCount, 4)
428    self.assertEqual(
429        self.mock_logger.output_msgs,
430        ['Storing experiment file in /usr/local/crosperf-results.',
431         'Storing results report in /usr/local/crosperf-results.',
432         'Storing email message body in /usr/local/crosperf-results.',
433         'Storing results of each benchmark run.'])
434
435
436if __name__ == '__main__':
437  unittest.main()
438