From patchwork Fri Sep 23 03:29:12 2011 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Paul Larson X-Patchwork-Id: 4292 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 87C3823EF6 for ; Fri, 23 Sep 2011 03:29:15 +0000 (UTC) Received: from mail-fx0-f52.google.com (mail-fx0-f52.google.com [209.85.161.52]) by fiordland.canonical.com (Postfix) with ESMTP id 630AFA18071 for ; Fri, 23 Sep 2011 03:29:15 +0000 (UTC) Received: by fxe23 with SMTP id 23so4784794fxe.11 for ; Thu, 22 Sep 2011 20:29:15 -0700 (PDT) Received: by 10.223.63.8 with SMTP id z8mr4222743fah.84.1316748555019; Thu, 22 Sep 2011 20:29:15 -0700 (PDT) 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.152.18.198 with SMTP id y6cs195182lad; Thu, 22 Sep 2011 20:29:14 -0700 (PDT) Received: by 10.216.210.21 with SMTP id t21mr1040944weo.31.1316748553508; Thu, 22 Sep 2011 20:29:13 -0700 (PDT) Received: from indium.canonical.com (indium.canonical.com. [91.189.90.7]) by mx.google.com with ESMTPS id z4si8940757wec.129.2011.09.22.20.29.13 (version=TLSv1/SSLv3 cipher=OTHER); Thu, 22 Sep 2011 20:29:13 -0700 (PDT) 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 1R6wRs-0003zD-Sl for ; Fri, 23 Sep 2011 03:29:12 +0000 Received: from ackee.canonical.com (localhost [127.0.0.1]) by ackee.canonical.com (Postfix) with ESMTP id CF4C9E05E3 for ; Fri, 23 Sep 2011 03:29:12 +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: 119 X-Launchpad-Notification-Type: branch-revision To: Linaro Patch Tracker From: noreply@launchpad.net Subject: [Branch ~linaro-validation/lava-dispatcher/trunk] Rev 119: Merge python logging branch from ChiThu Message-Id: <20110923032912.11071.63628.launchpad@ackee.canonical.com> Date: Fri, 23 Sep 2011 03:29:12 -0000 Reply-To: noreply@launchpad.net Sender: bounces@canonical.com Errors-To: bounces@canonical.com Precedence: bulk X-Generated-By: Launchpad (canonical.com); Revision="14012"; Instance="launchpad-lazr.conf" X-Launchpad-Hash: eff6e2fbc93240d07cf9f7fe13b88f2d8c6089ca Merge authors: Le Chi Thu le.chi.thu@linaro.org Related merge proposals: https://code.launchpad.net/~le-chi-thu/lava-dispatcher/improve-logging/+merge/76548 proposed by: Le Chi Thu (le-chi-thu) review: Approve - Paul Larson (pwlars) ------------------------------------------------------------ revno: 119 [merge] committer: Paul Larson branch nick: dispatcher-release-merge timestamp: Thu 2011-09-22 21:53:30 -0500 message: Merge python logging branch from ChiThu modified: .bzrignore lava-dispatch lava_dispatcher/actions/android_0xbench.py lava_dispatcher/actions/android_basic.py lava_dispatcher/actions/android_deploy.py lava_dispatcher/actions/boot_control.py lava_dispatcher/actions/deploy.py lava_dispatcher/actions/launch_control.py lava_dispatcher/actions/lava-test.py lava_dispatcher/android_client.py lava_dispatcher/client.py lava_dispatcher/config.py lava_dispatcher/default-config/lava-dispatcher/README lava_dispatcher/default-config/lava-dispatcher/lava-dispatcher.conf --- 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 '.bzrignore' --- .bzrignore 2011-09-09 00:57:07 +0000 +++ .bzrignore 2011-09-10 22:24:34 +0000 @@ -6,3 +6,4 @@ ./dist ./lava_dispatcher.egg-info ./build +./.idea \ No newline at end of file === modified file 'lava-dispatch' --- lava-dispatch 2011-08-17 00:52:46 +0000 +++ lava-dispatch 2011-09-23 02:53:30 +0000 @@ -22,9 +22,10 @@ import optparse import os import sys +import logging.config from lava_dispatcher import LavaTestJob - +from lava_dispatcher.config import get_config parser = optparse.OptionParser('%prog: lava-dispatch ') parser.add_option( @@ -32,6 +33,7 @@ (options, args) = parser.parse_args() + if len(args) != 1: parser.print_help() sys.exit(1) @@ -44,6 +46,17 @@ with open(args[0]) as fd: jobdata = fd.read() +# config the python logging + +FORMAT = '%(asctime)s %(levelname)s: %(message)s' +DATEFMT= '%Y-%m-%d %I:%M:%S %p' +logging.basicConfig(format=FORMAT,datefmt=DATEFMT) + +config = get_config("lava-dispatcher") +logging_level = config.get("LOGGING_LEVEL") +logging.root.setLevel(int(logging_level)) + job = LavaTestJob(jobdata, oob_file) + #FIXME Return status job.run() === modified file 'lava_dispatcher/actions/android_0xbench.py' --- lava_dispatcher/actions/android_0xbench.py 2011-07-20 06:53:10 +0000 +++ lava_dispatcher/actions/android_0xbench.py 2011-09-12 22:31:47 +0000 @@ -22,6 +22,7 @@ from lava_dispatcher.actions import BaseAndroidAction import time import pexpect +import logging class cmd_test_android_0xbench(BaseAndroidAction): def run(self): @@ -30,7 +31,7 @@ time.sleep(30) if not self.check_sys_bootup(): # TODO: Fetch the logcat message as attached - print "0xbench Test: sys bootup fail, aborted" + logging.warning("0xbench Test: sys bootup fail, aborted") return self.client.android_logcat_clear() @@ -46,7 +47,7 @@ try: self.client.android_logcat_monitor(pattern, timeout = 1200) except pexpect.TIMEOUT: - print "0xbench Test: TIMEOUT Fail" + logging.warning("0xbench Test: TIMEOUT Fail") raise finally: self.client.android_logcat_stop() === modified file 'lava_dispatcher/actions/android_basic.py' --- lava_dispatcher/actions/android_basic.py 2011-09-05 22:39:47 +0000 +++ lava_dispatcher/actions/android_basic.py 2011-09-12 22:31:47 +0000 @@ -24,6 +24,7 @@ import time import pexpect import sys +import logging from datetime import datetime from lava_dispatcher.android_util import savebundlefile @@ -34,7 +35,7 @@ time.sleep(30) if not self.check_sys_bootup(): # TODO: Fetch the logcat message as attachment - print "monkey run test skipped: sys bootup fail" + logging.warning("monkey run test skipped: sys bootup fail") return TIMEFORMAT = '%Y-%m-%dT%H:%M:%SZ' === modified file 'lava_dispatcher/actions/android_deploy.py' --- lava_dispatcher/actions/android_deploy.py 2011-09-14 04:18:40 +0000 +++ lava_dispatcher/actions/android_deploy.py 2011-09-23 02:53:30 +0000 @@ -24,6 +24,8 @@ import sys import shutil import traceback +import logging + from tempfile import mkdtemp from lava_dispatcher.utils import download, download_with_cache from lava_dispatcher.client import CriticalError @@ -33,14 +35,14 @@ LAVA_IMAGE_TMPDIR = self.context.lava_image_tmpdir LAVA_IMAGE_URL = self.context.lava_image_url client = self.client - print "deploying Android on %s" % client.hostname - print " boot: %s" % boot - print " system: %s" % system - print " data: %s" % data - print "Booting master image" + logging.info("deploying Android on %s" % client.hostname) + logging.info(" boot: %s" % boot) + logging.info(" system: %s" % system) + logging.info(" data: %s" % data) + logging.info("Booting master image") client.boot_master_image() - print "Waiting for network to come up" + logging.info("Waiting for network to come up") try: client.wait_network_up() except: === modified file 'lava_dispatcher/actions/boot_control.py' --- lava_dispatcher/actions/boot_control.py 2011-09-16 02:37:57 +0000 +++ lava_dispatcher/actions/boot_control.py 2011-09-23 02:53:30 +0000 @@ -20,6 +20,8 @@ # along # with this program; if not, see . +import logging + from lava_dispatcher.actions import BaseAction, BaseAndroidAction from lava_dispatcher.client import CriticalError @@ -44,6 +46,7 @@ client.proc.sendline("") status = 'pass' try: + logging.info("Boot Linaro image") client.boot_linaro_image() except: status = 'fail' @@ -56,4 +59,5 @@ """ def run(self): client = self.client + logging.info("Boot Master image") client.boot_master_image() === modified file 'lava_dispatcher/actions/deploy.py' --- lava_dispatcher/actions/deploy.py 2011-09-16 02:37:57 +0000 +++ lava_dispatcher/actions/deploy.py 2011-09-23 02:53:30 +0000 @@ -19,15 +19,15 @@ from commands import getoutput, getstatusoutput import os -import sys import re import shutil import traceback from tempfile import mkdtemp +import logging from lava_dispatcher.actions import BaseAction from lava_dispatcher.utils import download, download_with_cache -from lava_dispatcher.client import CriticalError +from lava_dispatcher.client import CriticalError, OperationFailed class cmd_deploy_linaro_image(BaseAction): @@ -35,15 +35,15 @@ LAVA_IMAGE_TMPDIR = self.context.lava_image_tmpdir LAVA_IMAGE_URL = self.context.lava_image_url client = self.client - print "deploying on %s" % client.hostname - print " hwpack: %s" % hwpack - print " rootfs: %s" % rootfs + logging.info("deploying on %s" % client.hostname) + logging.info(" hwpack: %s" % hwpack) + logging.info(" rootfs: %s" % rootfs) if kernel_matrix: - print " package: %s" % kernel_matrix[0] - print "Booting master image" + logging.info(" package: %s" % kernel_matrix[0]) + logging.info("Booting master image") client.boot_master_image() - print "Waiting for network to come up" + logging.info("Waiting for network to come up") try: client.wait_network_up() except: @@ -57,10 +57,11 @@ hwpack = hwpack.replace(LAVA_IMAGE_TMPDIR, '') hwpack = '/'.join(u.strip('/') for u in [ LAVA_IMAGE_URL, hwpack]) - print " hwpack with new kernel: %s" % hwpack + logging.info(" hwpack with new kernel: %s" % hwpack) + logging.info("About to handle with the build") try: - boot_tgz, root_tgz = self.generate_tarballs(hwpack, rootfs, + boot_tgz, root_tgz = self.generate_tarballs(hwpack, rootfs, use_cache) except: tb = traceback.format_exc() @@ -131,16 +132,24 @@ os.chmod(tarball_dir, 0755) #fix me: if url is not http-prefix, copy it to tarball_dir if use_cache: + logging.info("Downloading the %s file using cache" % hwpack_url) hwpack_path = download_with_cache(hwpack_url, tarball_dir, lava_cachedir) + + logging.info("Downloading the %s file using cache" % rootfs_url) rootfs_path = download_with_cache(rootfs_url, tarball_dir, lava_cachedir) else: + logging.info("Downloading the %s file" % hwpack_url) hwpack_path = download(hwpack_url, tarball_dir) + + logging.info("Downloading the %s file" % rootfs_url) rootfs_path = download(rootfs_url, tarball_dir) image_file = os.path.join(tarball_dir, "lava.img") cmd = ("sudo linaro-media-create --hwpack-force-yes --dev %s " "--image_file %s --binary %s --hwpack %s --image_size 3G" % (client.device_type, image_file, rootfs_path, hwpack_path)) + logging.info("Executing the linaro-media-create command") + logging.info(cmd) rc, output = getstatusoutput(cmd) if rc: shutil.rmtree(tarball_dir) @@ -163,7 +172,7 @@ def deploy_linaro_rootfs(self, rootfs): client = self.client - print "Deploying linaro image" + logging.info("Deploying linaro image") client.run_cmd_master('umount /dev/disk/by-label/testrootfs') client.run_cmd_master( 'mkfs.ext3 -q /dev/disk/by-label/testrootfs -L testrootfs') @@ -189,6 +198,7 @@ def deploy_linaro_bootfs(self, bootfs): client = self.client + logging.info("Deploying linaro bootfs") client.run_cmd_master('umount /dev/disk/by-label/testboot') client.run_cmd_master( 'mkfs.vfat /dev/disk/by-label/testboot -n testboot') @@ -206,7 +216,7 @@ client = self.client lava_cachedir = self.context.lava_cachedir LAVA_IMAGE_TMPDIR = self.context.lava_image_tmpdir - print "Deploying new kernel" + logging.info("Deploying new kernel") new_kernel = kernel_matrix[0] deb_prefix = kernel_matrix[1] filesuffix = new_kernel.split(".")[-1] @@ -224,7 +234,7 @@ kernel_path = download(new_kernel, tarball_dir) hwpack_path = download(hwpack, tarball_dir) - cmd = ("sudo linaro-hwpack-replace -t %s -p %s -r %s" + cmd = ("sudo linaro-hwpack-replace -t %s -p %s -r %s" % (hwpack_path, kernel_path, deb_prefix)) rc, output = getstatusoutput(cmd) === modified file 'lava_dispatcher/actions/launch_control.py' --- lava_dispatcher/actions/launch_control.py 2011-09-20 02:35:31 +0000 +++ lava_dispatcher/actions/launch_control.py 2011-09-23 02:53:30 +0000 @@ -23,6 +23,8 @@ import os import shutil import tarfile +import logging + from lava_dispatcher.actions import BaseAction from lava_dispatcher.client import OperationFailed from lava_dispatcher.utils import download @@ -34,8 +36,9 @@ class cmd_submit_results_on_host(BaseAction): def run(self, server, stream): dashboard = _get_dashboard(server) - + #Upload bundle files to dashboard + logging.info("Executing submit_results_on_host command") bundle_list = os.listdir("/tmp/%s" % self.context.lava_result_dir) for bundle_name in bundle_list: bundle = "/tmp/%s/%s" % (self.context.lava_result_dir, bundle_name) @@ -47,9 +50,9 @@ print >> self.context.oob_file, 'dashboard-put-result:', \ dashboard.put_ex(content, job_name, stream) except xmlrpclib.Fault, err: - print "xmlrpclib.Fault occurred" - print "Fault code: %d" % err.faultCode - print "Fault string: %s" % err.faultString + logging.warning("xmlrpclib.Fault occurred") + logging.warning("Fault code: %d" % err.faultCode) + logging.warning("Fault string: %s" % err.faultString) # After uploading, remove the bundle file at the host side os.remove(bundle) @@ -82,6 +85,7 @@ client.run_cmd_master('umount /mnt/root') #Create tarball of all results + logging.info("Creating lava results tarball") client.run_cmd_master('cd /tmp') client.run_cmd_master( 'tar czf /tmp/lava_results.tgz -C /tmp/%s .' % self.context.lava_result_dir) @@ -101,6 +105,8 @@ # download test result with a retry mechanism # set retry timeout to 2mins + + logging.info("About to download the result tarball to host") now = time.time() timeout = 120 try: @@ -111,9 +117,10 @@ if time.time() >= now+timeout: raise except: - print traceback.format_exc() + logging.warning(traceback.format_exc()) status = 'fail' err_msg = err_msg + " Can't retrieve test case results." + logging.warning(err_msg) client.run_cmd_master('kill %1') @@ -127,15 +134,17 @@ self.all_bundles.append(json.loads(content)) tar.close() except: - print traceback.format_exc() + logging.warning(traceback.format_exc()) status = 'fail' err_msg = err_msg + " Some test case result appending failed." + logging.warning(err_msg) finally: shutil.rmtree(tarball_dir) else: status = 'fail' err_msg = err_msg + "Getting master image IP address failed, \ no test case result retrived." + logging.warning(err_msg) #flush the serial log client.run_shell_command("") @@ -178,18 +187,18 @@ #Fix it: it's going to be deleted after transition if server.endswith("dashboard/"): server = ''.join([server, "xml-rpc/"]) - print "WARNING: Please use whole endpoint URL not just end with 'dashboard/', 'xml-rpc/' is added automatically now!!!" + logging.warn("Please use whole endpoint URL not just end with 'dashboard/', 'xml-rpc/' is added automatically now!!!") srv = xmlrpclib.ServerProxy(server, allow_none=True, use_datetime=True) if server.endswith("xml-rpc/"): - print "WARNING: Please use RPC2 endpoint instead, xml-rpc is deprecated!!!" + logging.warn("Please use RPC2 endpoint instead, xml-rpc is deprecated!!!") dashboard = srv elif server.endswith("RPC2/"): #include lava-server/RPC2/ dashboard = srv.dashboard else: - print "WARNING: The url seems not RPC2 or xml-rpc endpoints, please make sure it's a valid one!!!" + logging.warn("The url seems not RPC2 or xml-rpc endpoints, please make sure it's a valid one!!!") dashboard = srv.dashboard - print " server RPC endpoint URL: %s" %server + logging.info("server RPC endpoint URL: %s" % server) return dashboard === modified file 'lava_dispatcher/actions/lava-test.py' --- lava_dispatcher/actions/lava-test.py 2011-09-20 16:39:14 +0000 +++ lava_dispatcher/actions/lava-test.py 2011-09-23 02:53:30 +0000 @@ -22,6 +22,8 @@ from datetime import datetime import traceback +import logging + from lava_dispatcher.actions import BaseAction from lava_dispatcher.client import OperationFailed, CriticalError @@ -77,6 +79,7 @@ class cmd_lava_test_run(BaseAction): def run(self, test_name, timeout=-1): + logging.info("Executing lava_test_run %s command" % test_name) #Make sure in test image now client = self.client client.in_test_shell() @@ -104,6 +107,7 @@ lava-test deployment to test image rootfs by chroot """ def run(self, tests, install_python = None, register = None, timeout=2400): + logging.info("Executing lava_test_install (%s) command" % ",".join(tests)) client = self.client _setup_testrootfs(client) === modified file 'lava_dispatcher/android_client.py' --- lava_dispatcher/android_client.py 2011-09-20 06:14:43 +0000 +++ lava_dispatcher/android_client.py 2011-09-23 02:53:30 +0000 @@ -21,6 +21,7 @@ import sys import time from lava_dispatcher.client import LavaClient, OperationFailed, NetworkError, GeneralError +import logging from utils import string_to_list @@ -85,7 +86,7 @@ def android_logcat_stop(self): self.proc.sendcontrol('C') - print "logcat cancelled" + logging.info("logcat cancelled") # adb cound be connected through network def android_adb_connect(self, dev_ip): @@ -111,7 +112,7 @@ if device_ip is not None: dev_name = self.android_adb_connect(device_ip) if dev_name is not None: - print "dev_name = " + dev_name + logging.info("dev_name = " + dev_name) result = self.run_adb_shell_command(dev_name, "echo 1", "1") self.android_adb_disconnect(device_ip) return result === modified file 'lava_dispatcher/client.py' --- lava_dispatcher/client.py 2011-09-15 07:02:08 +0000 +++ lava_dispatcher/client.py 2011-09-23 02:53:30 +0000 @@ -24,6 +24,7 @@ from cStringIO import StringIO import traceback from utils import string_to_list +import logging class LavaClient(object): def __init__(self, context, config): @@ -203,7 +204,7 @@ try: self.wait_network_up() except: - print traceback.format_exc() + logging.warning(traceback.format_exc()) return None #tty device uses minimal match, see pexpect wiki #pattern1 = ".*\n(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})" @@ -215,10 +216,10 @@ #self.proc.sendline("") id = self.proc.expect([pattern1, pexpect.EOF, pexpect.TIMEOUT], timeout=5) - print "\nmatching pattern is %s" % id + logging.info("\nmatching pattern is %s" % id) if id == 0: ip = self.proc.match.groups()[0] - print "Master IP is %s" % ip + logging.info("Master IP is %s" % ip) return ip else: return None === modified file 'lava_dispatcher/config.py' --- lava_dispatcher/config.py 2011-09-09 00:52:17 +0000 +++ lava_dispatcher/config.py 2011-09-12 22:31:47 +0000 @@ -21,6 +21,7 @@ from ConfigParser import ConfigParser import os import StringIO +import logging default_config_path = os.path.join( @@ -60,7 +61,7 @@ config_files.reverse() if cp is None: cp = ConfigParser() - print "About to read %s" % str(config_files) + logging.debug("About to read %s" % str(config_files)) for path in config_files: _read_into(path, cp) return cp === modified file 'lava_dispatcher/default-config/lava-dispatcher/README' --- lava_dispatcher/default-config/lava-dispatcher/README 2011-09-08 23:35:05 +0000 +++ lava_dispatcher/default-config/lava-dispatcher/README 2011-09-12 22:31:47 +0000 @@ -39,3 +39,7 @@ a line "device_type = ", although other settings can be included here. You will definitely need to tell lava-dispatcher about the devices you have! + +* logging.conf + + This file defines settings for Python logging \ No newline at end of file === modified file 'lava_dispatcher/default-config/lava-dispatcher/lava-dispatcher.conf' --- lava_dispatcher/default-config/lava-dispatcher/lava-dispatcher.conf 2011-09-08 23:35:05 +0000 +++ lava_dispatcher/default-config/lava-dispatcher/lava-dispatcher.conf 2011-09-23 02:53:30 +0000 @@ -17,3 +17,10 @@ # Location for caching downloaded artifacts such as hwpacks and images LAVA_CACHEDIR = /linaro/images/cache +# Python logging level to use +# 10 = DEBUG +# 20 = INFO +# 30 = WARNING +# 40 = ERROR +# Messages with a lower number than LOGGING_LEVEL will be suppressed +LOGGING_LEVEL = 20