[Branch,~linaro-validation/lava-scheduler/trunk] Rev 209: improve logging in scheduler daemon

Message ID 20120830210810.22272.50951.launchpad@ackee.canonical.com
State Accepted
Headers show

Commit Message

Michael-Doyle Hudson Aug. 30, 2012, 9:08 p.m.
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 <michael.hudson@linaro.org>
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

Patch

=== 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