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