neo/sys/linux/runner/runner_lib.py

   1 # run doom process on a series of maps
   2 # can be used for regression testing, or to fetch media
   3 # keeps a log of each run ( see getLogfile )
   4
   5 # currently uses a basic stdout activity timeout to decide when to move on
   6 # using a periodic check of /proc/<pid>/status SleepAVG
   7 # when the sleep average is reaching 0, issue a 'quit' to stdout
   8
   9 # keeps serialized run status in runner.pickle
  10 # NOTE: can be used to initiate runs on failed maps only for instance etc.
  11
  12 # TODO: use the serialized and not the logs to sort the run order
  13
  14 # TODO: better logging. Use idLogger?
  15
  16 # TODO: configurable event when the process is found interactive
  17 # instead of emitting a quit, perform some warning action?
  18
  19 import sys, os, commands, string, time, traceback, pickle
  20
  21 from twisted.application import internet, service
  22 from twisted.internet import protocol, reactor, utils, defer
  23 from twisted.internet.task import LoopingCall
  24
  25 class doomClientProtocol( protocol.ProcessProtocol ):
  26
  27         # ProcessProtocol API
  28
  29         def connectionMade( self ):
  30                 self.logfile.write( 'connectionMade\n' )
  31
  32         def outReceived( self, data ):
  33                 print data
  34                 self.logfile.write( data )
  35
  36         def errReceived( self, data ):
  37                 print 'stderr: ' + data
  38                 self.logfile.write( 'stderr: ' + data )
  39
  40         def inConnectionLost( self ):
  41                 self.logfile.write( 'inConnectionLost\n' )
  42
  43         def outConnectionLost( self ):
  44                 self.logfile.write( 'outConnectionLost\n' )
  45
  46         def errConnectionLost( self ):
  47                 self.logfile.write( 'errConnectionLost\n' )
  48
  49         def processEnded( self, status_object ):
  50                 self.logfile.write( 'processEnded %s\n' % repr( status_object ) )
  51                 self.logfile.write( time.strftime( '%H:%M:%S', time.localtime( time.time() ) ) + '\n' )
  52                 self.logfile.close()
  53                 self.deferred.callback( None )
  54
  55         # mac management
  56         def __init__( self, logfilename, deferred ):
  57                 self.logfilename = logfilename
  58                 self.logfile = open( logfilename, 'a' )
  59                 self.logfile.write( time.strftime( '%H:%M:%S', time.localtime( time.time() ) ) + '\n' )
  60                 self.deferred = deferred
  61
  62 class doomService( service.Service ):
  63
  64         # current monitoring state
  65         # 0: nothing running
  66         # 1: we have a process running, we're monitoring it's CPU usage
  67         # 2: we issued a 'quit' to the process's stdin
  68         #   either going to get a processEnded, or a timeout
  69         # 3: we forced a kill because of error, timeout etc.
  70         state = 0
  71
  72         # load check period
  73         check_period = 10
  74
  75         # pickled status file
  76         pickle_file = 'runner.pickle'
  77
  78         # stores status indexed by filename
  79         # { 'mapname' : ( state, last_update ), .. }
  80         status = {}
  81
  82         # start the maps as multiplayer server
  83         multiplayer = 0
  84
  85         def __init__( self, bin, cmdline, maps, sort = 0, multiplayer = 0, blank_run = 0 ):
  86                 self.p_transport = None
  87                 self.multiplayer = multiplayer
  88                 self.blank_run = blank_run
  89                 if ( self.multiplayer ):
  90                         print 'Operate in multiplayer mode'
  91                 self.bin = os.path.abspath( bin )
  92                 if ( type( cmdline ) is type( '' ) ):
  93                         self.cmdline = string.split( cmdline, ' ' )
  94                 else:
  95                         self.cmdline = cmdline
  96                 self.maps = maps
  97                 if ( os.path.exists( self.pickle_file ) ):
  98                         print 'Loading pickled status %s' % self.pickle_file
  99                         handle = open( self.pickle_file, 'r' )
 100                         self.status = pickle.load( handle )
 101                         handle.close()
 102                 if ( sort ):
 103                         print 'Sorting maps oldest runs first'
 104                         maps_sorted = [ ]
 105                         for i in self.maps:
 106                                 i_log = self.getLogfile( i )
 107                                 if ( os.path.exists( i_log ) ):
 108                                         maps_sorted.append( ( i, os.path.getmtime( i_log ) ) )
 109                                 else:
 110                                         maps_sorted.append( ( i, 0 ) )
 111                         maps_sorted.sort( lambda x,y : cmp( x[1], y[1] ) )
 112                         self.maps = [ ]
 113                         if ( blank_run ):
 114                                 self.maps.append( 'blankrun' )
 115                         for i in maps_sorted:
 116                                 self.maps.append( i[ 0 ] )
 117                         print 'Sorted as: %s\n' % repr( self.maps )
 118
 119         def getLogfile( self, name ):
 120                 return 'logs/' + string.translate( name, string.maketrans( '/', '-' ) ) + '.log'
 121
 122         # deferred call when child process dies
 123         def processEnded( self, val ):
 124                 print 'child has died - state %d' % self.state
 125                 self.status[ self.maps[ self.i_map ] ] = ( self.state, time.time() )
 126                 self.i_map += 1
 127                 if ( self.i_map >= len( self.maps ) ):
 128                         reactor.stop()
 129                 else:
 130                         self.nextMap()
 131
 132         def processTimeout( self ):
 133                 self.p_transport.signalProcess( "KILL" )
 134
 135         def sleepAVGReply( self, val ):
 136                 try:
 137                         s = val[10:][:-2]
 138                         print 'sleepAVGReply %s%%' % s
 139                         if ( s == '0' ):
 140                                 # need twice in a row
 141                                 if ( self.state == 2 ):
 142                                         print 'child process is interactive'
 143                                         self.p_transport.write( 'quit\n' )
 144                                 else:
 145                                         self.state = 2
 146                         else:
 147                                 self.state = 1
 148 #                       else:
 149 #                               reactor.callLater( self.check_period, self.checkCPU )
 150                 except:
 151                         print traceback.format_tb( sys.exc_info()[2] )
 152                         print sys.exc_info()[0]
 153                         print 'exception raised in sleepAVGReply - killing process'
 154                         self.state = 3
 155                         self.p_transport.signalProcess( 'KILL' )
 156
 157         def sleepAVGTimeout( self ):
 158                 print 'sleepAVGTimeout - killing process'
 159                 self.state = 3
 160                 self.p_transport.signalProcess( 'KILL' )
 161
 162         # called at regular intervals to monitor the sleep average of the child process
 163         # when sleep reaches 0, it means the map is loaded and interactive
 164         def checkCPU( self ):
 165                 if ( self.state == 0 or self.p_transport is None or self.p_transport.pid is None ):
 166                         print 'checkCPU: no child process atm'
 167                         return
 168                 defer = utils.getProcessOutput( '/bin/bash', [ '-c', 'cat /proc/%d/status | grep SleepAVG' % self.p_transport.pid ] )
 169                 defer.addCallback( self.sleepAVGReply )
 170                 defer.setTimeout( 2, self.sleepAVGTimeout )
 171
 172         def nextMap( self ):
 173                 self.state = 0
 174                 name = self.maps[ self.i_map ]
 175                 print 'Starting map: ' + name
 176                 logfile = self.getLogfile( name )
 177                 print 'Logging to: ' + logfile
 178                 if ( self.multiplayer ):
 179                         cmdline = [ self.bin ] + self.cmdline + [ '+set', 'si_map', name ]
 180                         if ( name != 'blankrun' ):
 181                                 cmdline.append( '+spawnServer' )
 182                 else:
 183                         cmdline = [ self.bin ] + self.cmdline
 184                         if ( name != 'blankrun' ):
 185                                 cmdline += [ '+devmap', name ]
 186                 print 'Command line: ' + repr( cmdline )
 187                 self.deferred = defer.Deferred()
 188                 self.deferred.addCallback( self.processEnded )
 189                 self.p_transport = reactor.spawnProcess( doomClientProtocol( logfile, self.deferred ), self.bin, cmdline , path = os.path.dirname( self.bin ), env = os.environ )
 190                 self.state = 1
 191 #               # setup the CPU usage loop
 192 #               reactor.callLater( self.check_period, self.checkCPU )
 193
 194         def startService( self ):
 195                 print 'doomService startService'
 196                 loop = LoopingCall( self.checkCPU )
 197                 loop.start( self.check_period )
 198                 self.i_map = 0
 199                 self.nextMap()
 200
 201         def stopService( self ):
 202                 print 'doomService stopService'
 203                 if ( not self.p_transport.pid is None ):
 204                         self.p_transport.signalProcess( 'KILL' )
 205                 # serialize
 206                 print 'saving status to %s' % self.pickle_file
 207                 handle = open( self.pickle_file, 'w+' )
 208                 pickle.dump( self.status, handle )
 209                 handle.close()