Running enterprise_CFM_MeetAppSanity fails on m-62 if a mimo is connected to the setup. As we are targeting more and more automation for setups with mimo + regular main screen we need to be able to enroll the device.

I am not familiar with the enrollment logic, but one key difference i noticed in comparison to M-59 (and presubmably 60, not verified) is that the enrollment UI is now (61, 62) displayed on the mimo screen. Could it be the API is simply querying the wrong screen for the oob UI?

Test output:
(cr) (fresh) dtosic@spectre ~/trunk/src/third_party/autotest/files $ test_that --autotest_dir ~/trunk/src/third_party/autotest/files/     --board=panther 100.104.189.240 enterprise_CFM_MeetAppSanity --args "servo_host="
INFO:root:Identity added: /tmp/test_that_results__P0XDi/testing_rsa (/tmp/test_that_results__P0XDi/testing_rsa)
15:22:23 INFO | Began logging to /tmp/test_that_results__P0XDi
Adding labels [u'cros-version:ad_hoc_build', u'board:panther'] to host 100.104.189.240
08:22:23 INFO | Fetching suite for job named enterprise_CFM_MeetAppSanity...
08:22:27 INFO | Scheduling suite for job named enterprise_CFM_MeetAppSanity...
08:22:27 INFO | ... scheduled 1 job(s).
08:22:27 INFO | autoserv| Results placed in /tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity
08:22:27 INFO | autoserv| Logged pid 24899 to /tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/.autoserv_execute
08:22:27 INFO | autoserv| Starting new HTTP connection (1): metadata.google.internal
08:22:27 INFO | autoserv| Configuration file does not exist, ignoring: /etc/chrome-infra/ts-mon.json
08:22:27 INFO | autoserv| ts_mon monitoring is disabled because the endpoint provided is invalid or not supported:
08:22:27 INFO | autoserv| ts_mon was set up.
08:22:28 INFO | autoserv| I am PID 24899
08:22:28 INFO | autoserv| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_dlSwq1ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4 -o Protocol=2 -l root -p 22 100.104.189.240'
08:22:28 INFO | autoserv| get_network_stats: at-start RXbytes 18227689 TXbytes 1387015
08:22:28 INFO | autoserv| Not checking if job_repo_url contains autotest packages on ['100.104.189.240']
08:22:28 INFO | autoserv| Processing control file
08:22:28 INFO | autoserv| START	enterprise_CFM_MeetAppSanity	enterprise_CFM_MeetAppSanity	timestamp=1503494548	localtime=Aug 23 08:22:28
08:22:29 INFO | autoserv| Installing autotest on 100.104.189.240
08:22:29 INFO | autoserv| Using installation dir /tmp/sysinfo/autoserv-MhYsU8
08:22:29 INFO | autoserv| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08:22:30 INFO | autoserv| Installation of autotest completed from /mnt/host/source/src/third_party/autotest/files/client/
08:22:30 INFO | autoserv| Installing updated global_config.ini.
08:22:31 INFO | autoserv| Executing /tmp/sysinfo/autoserv-MhYsU8/bin/autotest /tmp/sysinfo/autoserv-MhYsU8/control phase 0
08:22:31 INFO | autoserv| Entered autotestd_monitor.
08:22:31 INFO | autoserv| Finished launching tail subprocesses.
08:22:31 INFO | autoserv| Finished waiting on autotestd to start.
08:22:31 INFO | autoserv| START	----	----	timestamp=1503494550	localtime=Aug 23 08:22:30
08:22:31 INFO | autoserv| GOOD	----	sysinfo.before	timestamp=1503494550	localtime=Aug 23 08:22:30
08:22:31 INFO | autoserv| END GOOD	----	----	timestamp=1503494550	localtime=Aug 23 08:22:30
08:22:31 INFO | autoserv| Got lock of exit_code_file.
08:22:31 INFO | autoserv| Released lock of exit_code_file and closed it.
08:22:33 INFO | autoserv| Killing child processes.
08:22:33 INFO | autoserv| Client complete
08:22:34 INFO | autoserv| Executing /tmp/sysinfo/autoserv-MhYsU8/bin/autotest /tmp/sysinfo/autoserv-MhYsU8/control phase 0
08:22:34 INFO | autoserv| Entered autotestd_monitor.
08:22:34 INFO | autoserv| Finished launching tail subprocesses.
08:22:34 INFO | autoserv| Finished waiting on autotestd to start.
08:22:34 INFO | autoserv| START	----	----	timestamp=1503494554	localtime=Aug 23 08:22:34
08:22:34 INFO | autoserv| GOOD	----	sysinfo.iteration.before	timestamp=1503494554	localtime=Aug 23 08:22:34
08:22:34 INFO | autoserv| END GOOD	----	----	timestamp=1503494554	localtime=Aug 23 08:22:34
08:22:34 INFO | autoserv| Got lock of exit_code_file.
08:22:34 INFO | autoserv| Released lock of exit_code_file and closed it.
08:22:36 INFO | autoserv| Killing child processes.
08:22:36 INFO | autoserv| Client complete
08:22:37 INFO | autoserv| Installing autotest on 100.104.189.240
08:22:37 INFO | autoserv| Using installation dir /usr/local/autotest
08:22:37 INFO | autoserv| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08:22:37 INFO | autoserv| Installation of autotest completed from /mnt/host/source/src/third_party/autotest/files/client/
08:22:37 INFO | autoserv| Installing updated global_config.ini.
08:22:37 INFO | autoserv| Setup the connection to RPC server, with retries...
08:22:37 INFO | autoserv| Waiting 90 seconds for XMLRPC server to start.
08:22:37 INFO | autoserv| <class 'socket.error'>([Errno 111] Connection refused)
08:22:37 INFO | autoserv| Retrying in 0.769903 seconds...
08:22:38 INFO | autoserv| XMLRPC server started successfully.
08:22:38 INFO | autoserv| START	----	reboot	timestamp=1503494558	localtime=Aug 23 08:22:38
08:22:38 INFO | autoserv| GOOD	----	reboot.start	timestamp=1503494558	localtime=Aug 23 08:22:38
08:23:35 INFO | autoserv| [stderr] mux_client_request_session: read from master failed: Broken pipe
08:23:35 INFO | autoserv| [stderr] Warning: Permanently added '100.104.189.240' (RSA) to the list of known hosts.
08:23:35 INFO | autoserv| Master ssh connection to 100.104.189.240 is down.
08:23:35 INFO | autoserv| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_qeOADBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4 -o Protocol=2 -l root -p 22 100.104.189.240'
08:23:36 INFO | autoserv| GOOD	----	reboot.verify	timestamp=1503494616	localtime=Aug 23 08:23:36
08:23:36 INFO | autoserv| END GOOD	----	reboot	kernel=3.8.11	localtime=Aug 23 08:23:36	timestamp=1503494616
08:23:36 INFO | autoserv| Setup the connection to RPC server, with retries...
08:23:36 INFO | autoserv| Waiting for RPC server "multimedia_xmlrpc_server" shutdown
08:23:36 INFO | autoserv| Shut down RPC server.
08:23:36 INFO | autoserv| Waiting 90 seconds for XMLRPC server to start.
08:23:36 INFO | autoserv| <class 'socket.error'>([Errno 111] Connection refused)
08:23:36 INFO | autoserv| Retrying in 1.138740 seconds...
08:23:37 INFO | autoserv| XMLRPC server started successfully.
08:23:37 INFO | autoserv| Retrying RPC 'cfm_main_screen.enroll_device'((), {}).
08:24:11 INFO | autoserv| Failed RPC 'cfm_main_screen.enroll_device'((), {}) with status [<type 'exceptions.Exception'>].
08:24:11 INFO | autoserv| START	----	reboot	timestamp=1503494651	localtime=Aug 23 08:24:11
08:24:11 INFO | autoserv| GOOD	----	reboot.start	timestamp=1503494651	localtime=Aug 23 08:24:11
08:25:08 INFO | autoserv| [stderr] mux_client_request_session: read from master failed: Broken pipe
08:25:08 INFO | autoserv| [stderr] Warning: Permanently added '100.104.189.240' (RSA) to the list of known hosts.
08:25:08 INFO | autoserv| Master ssh connection to 100.104.189.240 is down.
08:25:08 INFO | autoserv| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_VjIwvxssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=900 -o ServerAliveCountMax=3 -o ConnectionAttempts=4 -o Protocol=2 -l root -p 22 100.104.189.240'
08:25:08 INFO | autoserv| GOOD	----	reboot.verify	timestamp=1503494708	localtime=Aug 23 08:25:08
08:25:08 INFO | autoserv| END GOOD	----	reboot	kernel=3.8.11	localtime=Aug 23 08:25:08	timestamp=1503494708
08:25:08 INFO | autoserv| Installing autotest on 100.104.189.240
08:25:08 INFO | autoserv| Using installation dir /tmp/sysinfo/autoserv-MhYsU8
08:25:09 INFO | autoserv| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08:25:10 INFO | autoserv| Installation of autotest completed from /mnt/host/source/src/third_party/autotest/files/client/
08:25:10 INFO | autoserv| Installing updated global_config.ini.
08:25:10 INFO | autoserv| Executing /tmp/sysinfo/autoserv-MhYsU8/bin/autotest /tmp/sysinfo/autoserv-MhYsU8/control phase 0
08:25:11 INFO | autoserv| Entered autotestd_monitor.
08:25:11 INFO | autoserv| Finished launching tail subprocesses.
08:25:11 INFO | autoserv| Finished waiting on autotestd to start.
08:25:11 INFO | autoserv| START	----	----	timestamp=1503494710	localtime=Aug 23 08:25:10
08:25:11 INFO | autoserv| GOOD	----	sysinfo.iteration.after	timestamp=1503494710	localtime=Aug 23 08:25:10
08:25:11 INFO | autoserv| END GOOD	----	----	timestamp=1503494710	localtime=Aug 23 08:25:10
08:25:11 INFO | autoserv| Got lock of exit_code_file.
08:25:11 INFO | autoserv| Released lock of exit_code_file and closed it.
08:25:13 INFO | autoserv| Killing child processes.
08:25:13 INFO | autoserv| Client complete
08:25:13 INFO | autoserv| The test failed with the following exception
08:25:13 INFO | autoserv| Traceback (most recent call last):
08:25:13 INFO | autoserv| File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 606, in _exec
08:25:13 INFO | autoserv| _call_test_function(self.execute, *p_args, **p_dargs)
08:25:13 INFO | autoserv| File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 806, in _call_test_function
08:25:13 INFO | autoserv| return func(*args, **dargs)
08:25:13 INFO | autoserv| File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 470, in execute
08:25:13 INFO | autoserv| dargs)
08:25:13 INFO | autoserv| File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 347, in _call_run_once_with_retry
08:25:13 INFO | autoserv| postprocess_profiled_run, args, dargs)
08:25:13 INFO | autoserv| File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 380, in _call_run_once
08:25:13 INFO | autoserv| self.run_once(*args, **dargs)
08:25:13 INFO | autoserv| File "/mnt/host/source/src/third_party/autotest/files/server/site_tests/enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity.py", line 54, in run_once
08:25:13 INFO | autoserv| raise error.TestFail(str(e))
08:25:13 INFO | autoserv| TestFail: RPC error: cfm_main_screen.enroll_device
08:25:13 INFO | autoserv| Traceback (most recent call last):
08:25:13 INFO | autoserv| File "./multimedia_xmlrpc_server.py", line 90, in _dispatch
08:25:13 INFO | autoserv| return func(*params)
08:25:13 INFO | autoserv| File "/usr/local/autotest/cros/multimedia/cfm_facade_native.py", line 47, in enroll_device
08:25:13 INFO | autoserv| self._PWD)
08:25:13 INFO | autoserv| File "/usr/local/autotest/common_lib/cros/enrollment.py", line 37, in RemoraEnrollment
08:25:13 INFO | autoserv| SwitchToRemora(browser)
08:25:13 INFO | autoserv| File "/usr/local/autotest/common_lib/cros/enrollment.py", line 27, in SwitchToRemora
08:25:13 INFO | autoserv| utils.poll_for_condition(lambda: browser.oobe_exists, timeout=30)
08:25:13 INFO | autoserv| File "/usr/local/autotest/common_lib/utils.py", line 2738, in poll_for_condition
08:25:13 INFO | autoserv| raise TimeoutError(desc)
08:25:13 INFO | autoserv| TimeoutError: Timed out waiting for unnamed condition
08:25:13 INFO | autoserv| 
08:25:14 INFO | autoserv| Executing /tmp/sysinfo/autoserv-MhYsU8/bin/autotest /tmp/sysinfo/autoserv-MhYsU8/control phase 0
08:25:14 INFO | autoserv| Entered autotestd_monitor.
08:25:14 INFO | autoserv| Finished launching tail subprocesses.
08:25:14 INFO | autoserv| Finished waiting on autotestd to start.
08:25:14 INFO | autoserv| START	----	----	timestamp=1503494714	localtime=Aug 23 08:25:14
08:25:15 INFO | autoserv| GOOD	----	sysinfo.after	timestamp=1503494714	localtime=Aug 23 08:25:14
08:25:15 INFO | autoserv| END GOOD	----	----	timestamp=1503494714	localtime=Aug 23 08:25:14
08:25:15 INFO | autoserv| Got lock of exit_code_file.
08:25:15 INFO | autoserv| Released lock of exit_code_file and closed it.
08:25:17 INFO | autoserv| Killing child processes.
08:25:17 INFO | autoserv| Client complete
08:25:18 INFO | autoserv| FAIL	enterprise_CFM_MeetAppSanity	enterprise_CFM_MeetAppSanity	timestamp=1503494718	localtime=Aug 23 08:25:18	RPC error: cfm_main_screen.enroll_device
08:25:18 INFO | autoserv| Traceback (most recent call last):
08:25:18 INFO | autoserv| File "./multimedia_xmlrpc_server.py", line 90, in _dispatch
08:25:18 INFO | autoserv| return func(*params)
08:25:18 INFO | autoserv| File "/usr/local/autotest/cros/multimedia/cfm_facade_native.py", line 47, in enroll_device
08:25:18 INFO | autoserv| self._PWD)
08:25:18 INFO | autoserv| File "/usr/local/autotest/common_lib/cros/enrollment.py", line 37, in RemoraEnrollment
08:25:18 INFO | autoserv| SwitchToRemora(browser)
08:25:18 INFO | autoserv| File "/usr/local/autotest/common_lib/cros/enrollment.py", line 27, in SwitchToRemora
08:25:18 INFO | autoserv| utils.poll_for_condition(lambda: browser.oobe_exists, timeout=30)
08:25:18 INFO | autoserv| File "/usr/local/autotest/common_lib/utils.py", line 2738, in poll_for_condition
08:25:18 INFO | autoserv| raise TimeoutError(desc)
08:25:18 INFO | autoserv| TimeoutError: Timed out waiting for unnamed condition
08:25:18 INFO | autoserv| END FAIL	enterprise_CFM_MeetAppSanity	enterprise_CFM_MeetAppSanity	timestamp=1503494718	localtime=Aug 23 08:25:18
08:25:18 INFO | autoserv| Waiting for RPC server "multimedia_xmlrpc_server" shutdown
08:25:18 INFO | autoserv| Shut down RPC server.
08:25:18 INFO | autoserv| Finished processing control file
08:25:18 INFO | autoserv| tko parser: {'drone': 'spectre.lul.corp.google.com', 'user': 'autotest_system', 'job_started': 1503494547, 'hostname': '100.104.189.240', 'status_version': 1, 'experimental': 'False', 'label': 'ad_hoc_build/ad_hoc_suite/enterprise_CFM_MeetAppSanity'}
08:25:18 INFO | autoserv| tko parser: MACHINE NAME: 100.104.189.240
08:25:18 INFO | autoserv| tko parser: Unable to parse host keyval for 100.104.189.240
08:25:18 INFO | autoserv| tko parser: MACHINE GROUP:
08:25:18 INFO | autoserv| tko parser: parsing partial test ---- SERVER_JOB
08:25:18 INFO | autoserv| tko parser: parsing partial test enterprise_CFM_MeetAppSanity enterprise_CFM_MeetAppSanity
08:25:18 INFO | autoserv| tko parser: RUNNING: RUNNING
08:25:18 INFO | autoserv| Subdir: enterprise_CFM_MeetAppSanity
08:25:18 INFO | autoserv| Testname: enterprise_CFM_MeetAppSanity
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser: update RUNNING reason: RPC error: cfm_main_screen.enroll_device
08:25:18 INFO | autoserv| tko parser: The following lines were ignored:
08:25:18 INFO | autoserv| tko parser:   Traceback (most recent call last):
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:     File "./multimedia_xmlrpc_server.py", line 90, in _dispatch
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:       return func(*params)
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:     File "/usr/local/autotest/cros/multimedia/cfm_facade_native.py", line 47, in enroll_device
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:       self._PWD)
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:     File "/usr/local/autotest/common_lib/cros/enrollment.py", line 37, in RemoraEnrollment
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:       SwitchToRemora(browser)
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:     File "/usr/local/autotest/common_lib/cros/enrollment.py", line 27, in SwitchToRemora
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:       utils.poll_for_condition(lambda: browser.oobe_exists, timeout=30)
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:     File "/usr/local/autotest/common_lib/utils.py", line 2738, in poll_for_condition
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:       raise TimeoutError(desc)
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser:   TimeoutError: Timed out waiting for unnamed condition
08:25:18 INFO | autoserv| 
08:25:18 INFO | autoserv| tko parser: ---------------------------------
08:25:18 INFO | autoserv| tko parser: parsing test enterprise_CFM_MeetAppSanity enterprise_CFM_MeetAppSanity
08:25:18 INFO | autoserv| tko parser: ADD: FAIL
08:25:18 INFO | autoserv| Subdir: enterprise_CFM_MeetAppSanity
08:25:18 INFO | autoserv| Testname: enterprise_CFM_MeetAppSanity
08:25:18 INFO | autoserv| RPC error: cfm_main_screen.enroll_device
08:25:18 INFO | autoserv| tko parser: parsing test ---- SERVER_JOB
08:25:20 INFO | autoserv| There are no orphaned crashes; deleting /tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/crashinfo.100.104.189.240
08:25:20 INFO | autoserv| get_network_stats: at-end RXbytes 18299985 TXbytes 1748529
08:25:21 INFO | autoserv| record_state_duration failed: job_or_task_id=None, hostname=100.104.189.240, status=Running
-------------------------------------------------------------------------------------------------------------
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity                              [  FAILED  ]
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity                                FAIL: RPC error: cfm_main_screen.enroll_device
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity [  FAILED  ]
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity   FAIL: RPC error: cfm_main_screen.enroll_device
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity   08/23 08:23:35.535 ERROR|             utils:0280| [stderr] mux_client_request_session: read from master failed: Broken pipe
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity   08/23 08:23:35.596 ERROR|             utils:0280| [stderr] Warning: Permanently added '100.104.189.240' (RSA) to the list of known hosts.
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity   08/23 08:24:11.259 ERROR|remote_facade_fact:0134| Failed RPC 'cfm_main_screen.enroll_device'((), {}) with status [<type 'exceptions.Exception'>].
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity   08/23 08:25:08.215 ERROR|             utils:0280| [stderr] mux_client_request_session: read from master failed: Broken pipe
/tmp/test_that_results__P0XDi/results-1-enterprise_CFM_MeetAppSanity/enterprise_CFM_MeetAppSanity   08/23 08:25:08.274 ERROR|             utils:0280| [stderr] Warning: Permanently added '100.104.189.240' (RSA) to the list of known hosts.
-------------------------------------------------------------------------------------------------------------
Total PASS: 0/2 (0%)

08:25:22 INFO | Finished running tests. Results can be found in /tmp/test_that_results__P0XDi or /tmp/test_that_latest