From patchwork Sun Dec 11 17:24:14 2011 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Le Chi Thu X-Patchwork-Id: 5578 Return-Path: X-Original-To: patchwork@peony.canonical.com Delivered-To: patchwork@peony.canonical.com Received: from fiordland.canonical.com (fiordland.canonical.com [91.189.94.145]) by peony.canonical.com (Postfix) with ESMTP id 8B8DC23E0E for ; Sun, 11 Dec 2011 17:24:18 +0000 (UTC) Received: from mail-bw0-f52.google.com (mail-bw0-f52.google.com [209.85.214.52]) by fiordland.canonical.com (Postfix) with ESMTP id 65CD0A184EC for ; Sun, 11 Dec 2011 17:24:18 +0000 (UTC) Received: by bke17 with SMTP id 17so6237689bke.11 for ; Sun, 11 Dec 2011 09:24:18 -0800 (PST) Received: by 10.204.157.12 with SMTP id z12mr5308614bkw.18.1323624257993; Sun, 11 Dec 2011 09:24:17 -0800 (PST) X-Forwarded-To: linaro-patchwork@canonical.com X-Forwarded-For: patch@linaro.org linaro-patchwork@canonical.com Delivered-To: patches@linaro.org Received: by 10.205.129.2 with SMTP id hg2cs26589bkc; Sun, 11 Dec 2011 09:24:16 -0800 (PST) Received: by 10.180.92.42 with SMTP id cj10mr11078119wib.64.1323624254802; Sun, 11 Dec 2011 09:24:14 -0800 (PST) Received: from indium.canonical.com (indium.canonical.com. [91.189.90.7]) by mx.google.com with ESMTPS id j8si6849929wed.29.2011.12.11.09.24.14 (version=TLSv1/SSLv3 cipher=OTHER); Sun, 11 Dec 2011 09:24:14 -0800 (PST) Received-SPF: pass (google.com: best guess record for domain of bounces@canonical.com designates 91.189.90.7 as permitted sender) client-ip=91.189.90.7; Authentication-Results: mx.google.com; spf=pass (google.com: best guess record for domain of bounces@canonical.com designates 91.189.90.7 as permitted sender) smtp.mail=bounces@canonical.com Received: from ackee.canonical.com ([91.189.89.26]) by indium.canonical.com with esmtp (Exim 4.71 #1 (Debian)) id 1RZn8I-0001nH-2O for ; Sun, 11 Dec 2011 17:24:14 +0000 Received: from ackee.canonical.com (localhost [127.0.0.1]) by ackee.canonical.com (Postfix) with ESMTP id 03880E032C for ; Sun, 11 Dec 2011 17:24:14 +0000 (UTC) MIME-Version: 1.0 X-Launchpad-Project: lava-dispatcher X-Launchpad-Branch: ~linaro-validation/lava-dispatcher/trunk X-Launchpad-Message-Rationale: Subscriber X-Launchpad-Branch-Revision-Number: 179 X-Launchpad-Notification-Type: branch-revision To: Linaro Patch Tracker From: noreply@launchpad.net Subject: [Branch ~linaro-validation/lava-dispatcher/trunk] Rev 179: Added logging for sending and expecting statements. Message-Id: <20111211172414.9945.314.launchpad@ackee.canonical.com> Date: Sun, 11 Dec 2011 17:24:14 -0000 Reply-To: noreply@launchpad.net Sender: bounces@canonical.com Errors-To: bounces@canonical.com Precedence: bulk X-Generated-By: Launchpad (canonical.com); Revision="14450"; Instance="launchpad-lazr.conf" X-Launchpad-Hash: 79201c3be995d2162e419c98fa0522116e3eee6f Merge authors: Le Chi Thu le.chi.thu@linaro.org Related merge proposals: https://code.launchpad.net/~le-chi-thu/lava-dispatcher/log_send_and_expect/+merge/84673 proposed by: Le Chi Thu (le-chi-thu) review: Approve - Paul Larson (pwlars) review: Resubmit - Le Chi Thu (le-chi-thu) review: Approve - Michael Hudson-Doyle (mwhudson) ------------------------------------------------------------ revno: 179 [merge] committer: Le Chi Thu le.chi.thu@linaro.org branch nick: trunk timestamp: Sun 2011-12-11 18:21:38 +0100 message: Added logging for sending and expecting statements. modified: lava_dispatcher/client/base.py lava_dispatcher/client/master.py lava_dispatcher/connection.py --- lp:lava-dispatcher https://code.launchpad.net/~linaro-validation/lava-dispatcher/trunk You are subscribed to branch lp:lava-dispatcher. To unsubscribe from this branch go to https://code.launchpad.net/~linaro-validation/lava-dispatcher/trunk/+edit-subscription === modified file 'lava_dispatcher/client/base.py' --- lava_dispatcher/client/base.py 2011-11-30 01:17:02 +0000 +++ lava_dispatcher/client/base.py 2011-12-06 21:01:44 +0000 @@ -59,7 +59,7 @@ index = 0 while index == 0: index = self._connection.expect( - ['.+', pexpect.EOF, pexpect.TIMEOUT], timeout=1) + ['.+', pexpect.EOF, pexpect.TIMEOUT], timeout=1,lava_no_logging=1) def run(self, cmd, response=None, timeout=-1): """Run `cmd` and wait for a shell response. @@ -93,7 +93,7 @@ self._connection.expect(self._prompt_str, timeout=timeout) if self._wait_for_rc: match_id = self._connection.expect( - ['rc=(\d+\d?\d?)', pexpect.EOF, pexpect.TIMEOUT], timeout=2) + ['rc=(\d+\d?\d?)', pexpect.EOF, pexpect.TIMEOUT], timeout=2, lava_no_logging=1) if match_id == 0: rc = int(self._connection.match.groups()[0]) else: === modified file 'lava_dispatcher/client/master.py' --- lava_dispatcher/client/master.py 2011-12-07 01:35:56 +0000 +++ lava_dispatcher/client/master.py 2011-12-11 17:12:43 +0000 @@ -389,7 +389,7 @@ self.proc.hard_reboot() self._in_master_shell(300) self.proc.sendline('export PS1="$PS1 [rc=$(echo \$?)]: "') - self.proc.expect(self.master_str, timeout=10) + self.proc.expect(self.master_str, timeout=10, lava_no_logging=1) def _format_testpartition(self, session): logging.info("Format testboot and testrootfs partitions") @@ -530,7 +530,7 @@ """ self.proc.sendline("") match_id = self.proc.expect( - [self.master_str, pexpect.TIMEOUT], timeout=timeout) + [self.master_str, pexpect.TIMEOUT], timeout=timeout, lava_no_logging=1) if match_id == 1: raise OperationFailed logging.info("System is in master image now") === modified file 'lava_dispatcher/connection.py' --- lava_dispatcher/connection.py 2011-12-09 21:00:57 +0000 +++ lava_dispatcher/connection.py 2011-12-11 17:12:43 +0000 @@ -42,9 +42,29 @@ # pexpect-like interface. def sendline(self, *args, **kw): + logging.debug("sendline : %s" %args[0]) return self.proc.sendline(*args, **kw) + def send(self, *args, **kw): + logging.debug("sendline : %s" %args[0]) + return self.proc.send(*args, **kw) + def expect(self, *args, **kw): + # some expect should not be logged because it is so much noise. + if kw.has_key('lava_no_logging'): + del kw['lava_no_logging'] + return self.proc.expect(*args, **kw) + + if (kw.has_key('timeout')): + timeout = kw['timeout'] + else: + timeout = self.proc.timeout + + if len(args) == 1: + logging.debug("expect (%d): '%s'" %(timeout, args[0])) + else: + logging.debug("expect (%d): '%s'" %(timeout, str(args))) + return self.proc.expect(*args, **kw) def sendcontrol(self, *args, **kw): @@ -58,14 +78,14 @@ # Extra bits. def _enter_uboot(self): - self.proc.expect("Hit any key to stop autoboot") - self.proc.sendline("") + self.expect("Hit any key to stop autoboot") + self.sendline("") def soft_reboot(self): - self.proc.sendline("reboot") + self.sendline("reboot") # set soft reboot timeout 120s, or do a hard reset logging.info("Rebooting the system") - id = self.proc.expect( + id = self.expect( ['Restarting system.', 'The system is going down for reboot NOW', 'Will now restart', pexpect.TIMEOUT], timeout=120) if id not in [0,1,2]: @@ -97,8 +117,8 @@ logging.exception("_enter_uboot failed") self.hard_reboot() self._enter_uboot() - self.proc.sendline(boot_cmds[0]) + self.sendline(boot_cmds[0]) bootloader_prompt = re.escape(self.device_option('bootloader_prompt')) for line in range(1, len(boot_cmds)): - self.proc.expect(bootloader_prompt, timeout=300) - self.proc.sendline(boot_cmds[line]) + self.expect(bootloader_prompt, timeout=300) + self.sendline(boot_cmds[line])