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