Chrome OS Version: R68-10684.0.0

Steps To Reproduce:
(1) test_that -b grunt ${IP} firmware_Mosys

Expected Result:

PASS, or FAIL without "Exception occurred formatting message"

Actual Result:

11:36:18 INFO | autoserv| Execute mosys eeprom map|egrep "RW_SHARED|RW_SECTION_[AB]"
11:36:42 INFO | autoserv| Output ['host_firmware | RW_SECTION_A | 0x00000000 | 0x0021e000 |', 'host_firmware | RW_SECTION_B | 0x0021e000 | 0x0021e000 |', 'host_firmware | RW_SHARED | 0x00461000 | 0x00004000 |']
11:36:42 INFO | autoserv| Exception occurred formatting message: 'Expect non zero but got %s instead(%s)' using args (('0x00000000', 'host_firmware | RW_SECTION_A | 0x00000000 | 0x0021e000 |'),)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/autoserv", line 840, in <module>
11:36:42 INFO | autoserv| main()
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/autoserv", line 820, in main
11:36:42 INFO | autoserv| use_ssp)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/autoserv", line 601, in run_autoserv
11:36:42 INFO | autoserv| use_packaging=(not no_use_packaging))
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/server_job.py", line 805, in run
11:36:42 INFO | autoserv| self._execute_code(server_control_file, namespace)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/server_job.py", line 1328, in _execute_code
11:36:42 INFO | autoserv| execfile(code_file, namespace, namespace)
11:36:42 INFO | autoserv| File "/tmp/test_that_results__NO7yb/results-1-firmware_Mosys/control.srv", line 32, in <module>
11:36:42 INFO | autoserv| parallel_simple(run_mosys, machines)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/subcommand.py", line 98, in parallel_simple
11:36:42 INFO | autoserv| function(arg)
11:36:42 INFO | autoserv| File "/tmp/test_that_results__NO7yb/results-1-firmware_Mosys/control.srv", line 30, in run_mosys
11:36:42 INFO | autoserv| disable_sysinfo=True, dev_mode=False, tag="normal")
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/server_job.py", line 886, in run_test
11:36:42 INFO | autoserv| result = self._run_group(testname, subdir, group_func)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/server_job.py", line 898, in _run_group
11:36:42 INFO | autoserv| result = function(*args, **dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/server_job.py", line 874, in group_func
11:36:42 INFO | autoserv| test.runtest(self, url, tag, args, dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/test.py", line 302, in runtest
11:36:42 INFO | autoserv| *logging_args)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/common_lib/test.py", line 919, in runtest
11:36:42 INFO | autoserv| mytest._exec(args, dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/common_lib/test.py", line 631, in _exec
11:36:42 INFO | autoserv| _call_test_function(self.execute, *p_args, **p_dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/common_lib/test.py", line 831, in _call_test_function
11:36:42 INFO | autoserv| return func(*args, **dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/common_lib/test.py", line 495, in execute
11:36:42 INFO | autoserv| dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/common_lib/test.py", line 362, in _call_run_once_with_retry
11:36:42 INFO | autoserv| postprocess_profiled_run, args, dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/common_lib/test.py", line 400, in _call_run_once
11:36:42 INFO | autoserv| self.run_once(*args, **dargs)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/server/site_tests/firmware_Mosys/firmware_Mosys.py", line 229, in run_once
11:36:42 INFO | autoserv| (row[2], line))
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 1601, in error
11:36:42 INFO | autoserv| root.error(msg, *args, **kwargs)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 1191, in error
11:36:42 INFO | autoserv| self._log(ERROR, msg, args, **kwargs)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 1284, in _log
11:36:42 INFO | autoserv| self.handle(record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 1294, in handle
11:36:42 INFO | autoserv| self.callHandlers(record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 1334, in callHandlers
11:36:42 INFO | autoserv| hdlr.handle(record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 757, in handle
11:36:42 INFO | autoserv| self.emit(record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 955, in emit
11:36:42 INFO | autoserv| StreamHandler.emit(self, record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 887, in emit
11:36:42 INFO | autoserv| self.handleError(record)
11:36:42 INFO | autoserv| File "/build/grunt/usr/local/build/autotest/client/setup_modules.py", line 86, in _autotest_logging_handle_error
11:36:42 INFO | autoserv| traceback.print_stack()
11:36:42 INFO | autoserv| --------------------------------------------------
11:36:42 INFO | autoserv| Traceback (most recent call last):
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 859, in emit
11:36:42 INFO | autoserv| msg = self.format(record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 732, in format
11:36:42 INFO | autoserv| return fmt.format(record)
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 471, in format
11:36:42 INFO | autoserv| record.message = record.getMessage()
11:36:42 INFO | autoserv| File "/usr/lib64/python2.7/logging/__init__.py", line 335, in getMessage
11:36:42 INFO | autoserv| msg = msg % self.args
11:36:42 INFO | autoserv| TypeError: not enough arguments for format string
11:36:42 INFO | autoserv| Future logging formatting exceptions disabled.
11:36:42 INFO | autoserv| Execute mosys eeprom map|egrep "RW_SHARED|RW_SECTION_[AB]" failed


How frequently does this problem reproduce? (Always, sometimes, hard to
reproduce?)

Always