From patchwork Thu Aug 30 21:08:10 2012 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Michael-Doyle Hudson X-Patchwork-Id: 11071 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 3824423E52 for ; Thu, 30 Aug 2012 21:08:13 +0000 (UTC) Received: from mail-iy0-f180.google.com (mail-iy0-f180.google.com [209.85.210.180]) by fiordland.canonical.com (Postfix) with ESMTP id 7D44FA192C9 for ; Thu, 30 Aug 2012 21:07:36 +0000 (UTC) Received: by iafj25 with SMTP id j25so3675435iaf.11 for ; Thu, 30 Aug 2012 14:08:12 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=x-forwarded-to:x-forwarded-for:delivered-to:received-spf :content-type:mime-version:x-launchpad-project:x-launchpad-branch :x-launchpad-message-rationale:x-launchpad-branch-revision-number :x-launchpad-notification-type:to:from:subject:message-id:date :reply-to:sender:errors-to:precedence:x-generated-by :x-launchpad-hash:x-gm-message-state; bh=rhXnmnWbwtd930Eh3lPTnqsnLoVCQNvdekEfnhe67SU=; b=kuYgoTBL7Sb1NeQyd83xUQP4Sxu0V9aSkGPfjOA/cwRGYKfq3IMx4i+0dZypn9vKMF Buekkei9VNGg2THcAkJB3qhH3Uxf32Cd+tI6fsz8iclb+oPOVfau1xXumpXzE4pEuN5C iAjj1W9fMs7ZNFsz1ScghC/zGq+r0JSDTj18yCSrKxD5xTir/FC1PyG+8Cg4ro3SYWFz NhRb+ITvETKen3LmPjvfWUiRp4LwASHk4ryHCKsDtleSJkh1ForLKEDacLLllDZ/6pjH m4vH3pergNjNEXhA2M5WInNwr33xVPoo3WhPTrRoRX9+wDeAY8A5MP+wkIoDeNY5EVTO urrA== Received: by 10.50.217.227 with SMTP id pb3mr2441539igc.28.1346360892169; Thu, 30 Aug 2012 14:08:12 -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.50.184.232 with SMTP id ex8csp31434igc; Thu, 30 Aug 2012 14:08:11 -0700 (PDT) Received: by 10.180.107.163 with SMTP id hd3mr2855164wib.19.1346360890995; Thu, 30 Aug 2012 14:08:10 -0700 (PDT) Received: from indium.canonical.com (indium.canonical.com. [91.189.90.7]) by mx.google.com with ESMTPS id f2si3685722wiz.13.2012.08.30.14.08.10 (version=TLSv1/SSLv3 cipher=OTHER); Thu, 30 Aug 2012 14:08:10 -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 1T7ByE-0006Lb-8l for ; Thu, 30 Aug 2012 21:08:10 +0000 Received: from ackee.canonical.com (localhost [127.0.0.1]) by ackee.canonical.com (Postfix) with ESMTP id 35F1FE03E6 for ; Thu, 30 Aug 2012 21:08:10 +0000 (UTC) MIME-Version: 1.0 X-Launchpad-Project: lava-scheduler X-Launchpad-Branch: ~linaro-validation/lava-scheduler/trunk X-Launchpad-Message-Rationale: Subscriber X-Launchpad-Branch-Revision-Number: 209 X-Launchpad-Notification-Type: branch-revision To: Linaro Patch Tracker From: noreply@launchpad.net Subject: [Branch ~linaro-validation/lava-scheduler/trunk] Rev 209: improve logging in scheduler daemon Message-Id: <20120830210810.22272.50951.launchpad@ackee.canonical.com> Date: Thu, 30 Aug 2012 21:08:10 -0000 Reply-To: noreply@launchpad.net Sender: bounces@canonical.com Errors-To: bounces@canonical.com Precedence: bulk X-Generated-By: Launchpad (canonical.com); Revision="15877"; Instance="launchpad-lazr.conf" X-Launchpad-Hash: 2e84fe20d8bc6d9684eac343c729e524b42e1301 X-Gm-Message-State: ALoCoQmL1aHM4ksgD/Y/Ro6KZaKImP8lOSc1ntBR4b06wpEzIoMZHJAF0j98x3OpKRvah1xr3HqF Merge authors: Michael Hudson-Doyle (mwhudson) Related merge proposals: https://code.launchpad.net/~mwhudson/lava-scheduler/do-not-drop-monitor-output/+merge/121982 proposed by: Michael Hudson-Doyle (mwhudson) review: Approve - Andy Doan (doanac) ------------------------------------------------------------ revno: 209 [merge] committer: Michael Hudson-Doyle branch nick: trunk timestamp: Fri 2012-08-31 09:07:30 +1200 message: improve logging in scheduler daemon modified: fake-dispatcher lava_scheduler_daemon/board.py --- lp:lava-scheduler https://code.launchpad.net/~linaro-validation/lava-scheduler/trunk You are subscribed to branch lp:lava-scheduler. To unsubscribe from this branch go to https://code.launchpad.net/~linaro-validation/lava-scheduler/trunk/+edit-subscription === modified file 'fake-dispatcher' --- fake-dispatcher 2012-03-27 21:30:51 +0000 +++ fake-dispatcher 2012-08-30 03:58:19 +0000 @@ -11,15 +11,8 @@ echo starting processing $1 echo error >&2 -for i in `seq 100`; do +for i in `seq 10`; do echo p $i -cat $1 -echo -done -for i in `seq 300`; do sleep 1 -echo $i -cat $1 -echo done echo dashboard-put-result: http://disney.com >&3 === modified file 'lava_scheduler_daemon/board.py' --- lava_scheduler_daemon/board.py 2012-07-10 22:45:19 +0000 +++ lava_scheduler_daemon/board.py 2012-08-30 03:58:19 +0000 @@ -5,7 +5,7 @@ import tempfile import logging -from twisted.internet.error import ProcessExitedAlready +from twisted.internet.error import ProcessDone, ProcessExitedAlready from twisted.internet.protocol import ProcessProtocol from twisted.internet import defer, task from twisted.protocols.basic import LineReceiver @@ -64,7 +64,13 @@ self.job.cancel("exceeded log size limit") self.log_file.flush() + def processExited(self, reason): + self.logger.info("processExited for %s: %s", + self.job.board_name, reason.value) + def processEnded(self, reason): + self.logger.info("processEnded for %s: %s", + self.job.board_name, reason.value) self.log_file.close() self.deferred.callback(reason.value.exitCode) @@ -170,10 +176,23 @@ lambda r:exit_code) -class SimplePP(ProcessProtocol): - def __init__(self, d): +class SchedulerMonitorPP(ProcessProtocol): + + def __init__(self, d, board_name): self.d = d + self.board_name = board_name + self.logger = logging.getLogger(__name__ + '.SchedulerMonitorPP') + + def childDataReceived(self, childFD, data): + self.logger.warning( + "scheduler monitor for %s produced output: %r on fd %s", + self.board_name, data, childFD) + def processEnded(self, reason): + if not reason.check(ProcessDone): + self.logger.error( + "scheduler monitor for %s crashed: %s", + self.board_name, reason) self.d.callback(None) @@ -199,6 +218,7 @@ with os.fdopen(fd, 'wb') as f: json.dump(json_data, f) + childFDs = {0:0, 1:1, 2:2} if self.use_celery: args = [ 'setsid', 'lava', 'celery-schedulermonitor', @@ -210,10 +230,11 @@ '-l', self.daemon_options['LOG_LEVEL']] if self.daemon_options['LOG_FILE_PATH']: args.extend(['-f', self.daemon_options['LOG_FILE_PATH']]) + childFDs = None self.logger.info('executing "%s"', ' '.join(args)) self.reactor.spawnProcess( - SimplePP(d), 'setsid', childFDs={0:0, 1:1, 2:2}, - env=None, args=args) + SchedulerMonitorPP(d, self.board_name), 'setsid', + childFDs=childFDs, env=None, args=args) d.addBoth(self._exited) return d