=== modified file 'lava_dispatcher/__init__.py'
--- lava_dispatcher/__init__.py	2011-10-27 02:32:02 +0000
+++ lava_dispatcher/__init__.py	2011-10-27 06:12:13 +0000
@@ -25,6 +25,7 @@
 from uuid import uuid1
 import base64
 import pexpect
+import logging
 
 from lava_dispatcher.actions import get_all_cmds
 from lava_dispatcher.config import get_config, get_device_config
@@ -87,6 +88,7 @@
                     status = 'pass'
                 finally:
                     err_msg = ""
+                    logging.info("Action %s finished." % cmd['command'])
                     if status == 'fail':
                         err_msg = "Lava failed at action %s with error: %s\n" %\
                                   (cmd['command'], err)

=== modified file 'lava_dispatcher/actions/android_deploy.py'
--- lava_dispatcher/actions/android_deploy.py	2011-10-20 18:24:55 +0000
+++ lava_dispatcher/actions/android_deploy.py	2011-10-24 07:49:16 +0000
@@ -38,7 +38,7 @@
         logging.info("  boot: %s" % boot)
         logging.info("  system: %s" % system)
         logging.info("  data: %s" % data)
-        logging.info("Booting master image")
+        logging.info("Boot master image")
         client.boot_master_image()
 
         logging.info("Waiting for network to come up...")

=== modified file 'lava_dispatcher/actions/boot_control.py'
--- lava_dispatcher/actions/boot_control.py	2011-10-26 02:59:28 +0000
+++ lava_dispatcher/actions/boot_control.py	2011-10-27 09:11:47 +0000
@@ -34,8 +34,8 @@
         client.proc.sendline("")
         try:
             client.boot_linaro_android_image()
-        except:
-            logging.exception("boot_linaro_android_image failed")
+        except Exception as e:
+            logging.exception("boot_linaro_android_image failed: %s" % e)
             raise CriticalError("Failed to boot test image.")
 
 class cmd_boot_linaro_image(BaseAction):
@@ -61,5 +61,5 @@
     """
     def run(self):
         client = self.client
-        logging.info("Boot Master image")
+        logging.info("Boot master image")
         client.boot_master_image()

=== modified file 'lava_dispatcher/actions/lava-test.py'
--- lava_dispatcher/actions/lava-test.py	2011-10-26 02:59:28 +0000
+++ lava_dispatcher/actions/lava-test.py	2011-10-27 06:12:13 +0000
@@ -91,7 +91,10 @@
         logging.info("Executing lava_test_run %s command" % test_name)
         #Make sure in test image now
         client = self.client
-        client.in_test_shell()
+        try:
+            client.in_test_shell()
+        except:
+            client.boot_linaro_image()
         client.run_cmd_tester('mkdir -p %s' % self.context.lava_result_dir)
         client.export_display()
         bundle_name = test_name + "-" + datetime.now().strftime("%H%M%S")

=== modified file 'lava_dispatcher/client.py'
--- lava_dispatcher/client.py	2011-10-27 01:09:17 +0000
+++ lava_dispatcher/client.py	2011-10-27 09:11:47 +0000
@@ -99,15 +99,18 @@
             timeout=timeout)
         if id == 1:
             raise OperationFailed
+        logging.info("System is in master image now")
 
-    def in_test_shell(self):
+    def in_test_shell(self, timeout=10):
         """
         Check that we are in a shell on the test image
         """
         self.proc.sendline("")
-        match_id = self.proc.expect([self.tester_str, pexpect.TIMEOUT])
+        match_id = self.proc.expect([self.tester_str, pexpect.TIMEOUT],
+                    timeout=timeout)
         if match_id == 1:
             raise OperationFailed
+        logging.info("System is in test image now")
 
     def boot_master_image(self):
         """
@@ -122,20 +125,20 @@
             self.proc.hard_reboot()
             self.in_master_shell(300)
         self.proc.sendline('export PS1="$PS1 [rc=$(echo \$?)]: "')
-        self.proc.expect(self.master_str)
+        self.proc.expect(self.master_str, timeout=10)
 
     def boot_linaro_image(self):
         """
         Reboot the system to the test image
         """
         self.proc._boot(self.boot_cmds)
-        self.in_test_shell()
+        self.in_test_shell(300)
         # set PS1 to include return value of last command
         # Details: system PS1 is set in /etc/bash.bashrc and user PS1 is set in
         # /root/.bashrc, it is
         # "${debian_chroot:+($debian_chroot)}\u@\h:\w\$ "
         self.proc.sendline('export PS1="$PS1 [rc=$(echo \$?)]: "')
-        self.proc.expect(self.tester_str)
+        self.proc.expect(self.tester_str, timeout=10)
 
     def run_shell_command(self, cmd, response=None, timeout=-1):
         self.empty_pexpect_buffer()
@@ -228,7 +231,7 @@
 
     def boot_linaro_android_image(self):
         """Reboot the system to the test android image."""
-        self._boot(string_to_list(self.config.get('boot_cmds_android')))
+        self.proc._boot(string_to_list(self.config.get('boot_cmds_android')))
         self.in_test_shell()
         self.proc.sendline("export PS1=\"root@linaro: \"")
 

=== modified file 'lava_dispatcher/connection.py'
--- lava_dispatcher/connection.py	2011-10-26 03:24:05 +0000
+++ lava_dispatcher/connection.py	2011-10-27 06:12:13 +0000
@@ -66,6 +66,7 @@
     def soft_reboot(self):
         self.proc.sendline("reboot")
         # set soft reboot timeout 120s, or do a hard reset
+        logging.info("Rebooting the system")
         id = self.proc.expect(
             ['Will now restart', pexpect.TIMEOUT], timeout=120)
         if id != 0:
@@ -79,12 +80,13 @@
 
     def _make_connection(self, sio):
         cmd = "conmux-console %s" % self.device_option("hostname")
-        proc = pexpect.spawn(cmd, timeout=3600, logfile=sio)
+        proc = pexpect.spawn(cmd, timeout=1200, logfile=sio)
         #serial can be slow, races do funny things if you don't increase delay
         proc.delaybeforesend=1
         return proc
 
     def hard_reboot(self):
+        logging.info("Perform hard reset on the system")
         self.proc.send("~$")
         self.proc.sendline("hardreset")
         # XXX Workaround for snowball

