At a high level, VM test phases run three different tests:
"smoke_suite", "dev_mode_test", and "cros_vm_test".
The cros_vm_test itself is broken into smaller pieces,
including a test that runs "cros flash".  If that cros
flash test fails, the logs are inadequate.  In particular,
there's no logging of the output from 'ssh' commands to the
target VM, and after the failure, there's nothing from the
update_engine log.


Here's a sample snipped from a recent failure:

3:35:55: INFO: Running test for cros flash.
03:35:55: INFO: Test to flash the VM device with the latest image.
03:35:55: INFO: RunCommand: cros flash --no-wipe --no-reboot ssh://localhost:56385 latest
03:43:08: ERROR: Failed to flash the VM device.
03:43:08: INFO: 
----------- Start of cros flash log -----------
03:35:56: NOTICE: Preparing to update the remote device localhost
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module httplib2 was already imported from /b/cbuild/shared_internal/chromite/third_party/httplib2/__init__.pyc, but /usr/local/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module simplejson was already imported from /b/build/third_party/simplejson/__init__.pyc, but /usr/local/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module oauth2client was already imported from /b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/oauth2client/__init__.pyc, but /usr/local/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module six was already imported from /b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/six/__init__.pyc, but /usr/local/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module apiclient was already imported from /b/cbuild/shared_internal/chromite/third_party/apiclient/__init__.pyc, but /usr/local/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module googleapiclient was already imported from /b/cbuild/shared_internal/chromite/third_party/googleapiclient/__init__.pyc, but /usr/local/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
/b/cbuild/shared_internal/chromite/third_party/swarming.client/third_party/google/__init__.py:1: UserWarning: Module cherrypy was already imported from /b/build/third_party/cherrypy/__init__.pyc, but /usr/lib/python2.7/dist-packages is being added to sys.path
  __import__('pkg_resources').declare_namespace(__name__)
03:43:05: ERROR: Rootfs update failed.
03:43:06: WARNING: --- Start output from /mnt/stateful_partition/cros-flash/tmp.fHootCgFZI/dev_server.log ---[26/Apr/2016:03:42:45] DEVSERVER Using cache directory /mnt/stateful_partition/cros-flash/tmp.fHootCgFZI/static/cache
[26/Apr/2016:03:42:45] DEVSERVER Serving from /mnt/stateful_partition/cros-flash/tmp.fHootCgFZI/static
[26/Apr/2016:03:42:45] XBUDDY Using shadow config file stored at /mnt/stateful_partition/cros-flash/tmp.fHootCgFZI/src/shadow_xbuddy_config.ini
[26/Apr/2016:03:42:45] ENGINE Listening for SIGHUP.
[26/Apr/2016:03:42:45] ENGINE Listening for SIGTERM.
[26/Apr/2016:03:42:45] ENGINE Listening for SIGUSR1.
[26/Apr/2016:03:42:45] ENGINE Bus STARTING
[26/Apr/2016:03:42:45] ENGINE Started monitor thread '_TimeoutMonitor'.
[26/Apr/2016:03:42:45] ENGINE PID 3397 written to '/tmp/devserver_wrapper.pid'.
[26/Apr/2016:03:42:45] ENGINE (wait_for_free_port) No cached port to wait for.
[26/Apr/2016:03:42:45] ENGINE Port 38339 written to '/mnt/stateful_partition/cros-flash/tmp.fHootCgFZI/dev_server.port'.
[26/Apr/2016:03:42:45] ENGINE (wait_for_occupied_port) Waiting for actual port 38339.
[26/Apr/2016:03:42:45] ENGINE Serving on 0.0.0.0:0
[26/Apr/2016:03:42:45] ENGINE Bus STARTED
127.0.0.1 - - [26/Apr/2016:03:42:50] "GET /check_health HTTP/1.1" 200 326 "" "Wget/1.16 (linux-gnu)"
[26/Apr/2016:03:42:51] UPDATE Using static url base http://127.0.0.1:38339/static
[26/Apr/2016:03:42:51] UPDATE Handling update ping as http://127.0.0.1:38339
[26/Apr/2016:03:42:51] UPDATE Update Check Received. Client is using protocol version: 3.0
[26/Apr/2016:03:42:51] UPDATE Update label/file: pregenerated/chromiumos_test_image.bin
[26/Apr/2016:03:42:51] UPDATE client version 7978.64.0 latest version 9999.0.0
[26/Apr/2016:03:43:04] UPDATE Responding to client to use url http://127.0.0.1:38339/static/pregenerated/update.gz to get image
127.0.0.1 - - [26/Apr/2016:03:43:04] "POST /update/pregenerated HTTP/1.1" 200 911 "" ""
[26/Apr/2016:03:43:04] UPDATE Using static url base http://127.0.0.1:38339/static
[26/Apr/2016:03:43:04] UPDATE Handling update ping as http://127.0.0.1:38339
[26/Apr/2016:03:43:04] UPDATE A non-update event notification received. Returning an ack.
127.0.0.1 - - [26/Apr/2016:03:43:04] "POST /update/pregenerated HTTP/1.1" 200 253 "" ""
--- End output from /mnt/stateful_partition/cros-flash/tmp.fHootCgFZI/dev_server.log ---
03:43:07: ERROR: Device update failed.
03:43:07: ERROR: cros flash failed before completing.
03:43:07: ERROR: Update failed with unexpected update status: UPDATE_STATUS_IDLE
-----------  End of cros flash log  -----------