sercom/tester.py

   1 # vim: set et sw=4 sts=4 encoding=utf-8 foldmethod=marker:
   2
   3 from sercom.model import Entrega, CasoDePrueba
   4 from sercom.model import TareaFuente, TareaPrueba, ComandoFuente, ComandoPrueba
   5 from zipfile import ZipFile, BadZipfile
   6 from cStringIO import StringIO
   7 from shutil import rmtree
   8 from datetime import datetime
   9 from os.path import join
  10 from turbogears import config
  11 import subprocess as sp
  12 import os, sys, pwd, grp
  13 import resource as rsrc
  14 import logging
  15
  16 log = logging.getLogger('sercom.tester')
  17
  18 error_interno = _(u'\n**Error interno al preparar la entrega.**')
  19
  20 class UserInfo(object): #{{{
  21     def __init__(self, user):
  22         try:
  23             info = pwd.getpwnam(user)
  24         except:
  25             info = pwd.get(int(user))
  26         self.user = info[0]
  27         self.uid = info[2]
  28         self.gid = info[3]
  29         self.name = info[4]
  30         self.home = info[5]
  31         self.shell = info[6]
  32         self.group = grp.getgrgid(self.gid)[0]
  33 #}}}
  34
  35 user_info = UserInfo(config.get('sercom.tester.user', 65534))
  36
  37 def check_call(*popenargs, **kwargs): #{{{ XXX Python 2.5 forward-compatibility
  38     """Run command with arguments.  Wait for command to complete.  If
  39     the exit code was zero then return, otherwise raise
  40     CalledProcessError.  The CalledProcessError object will have the
  41     return code in the returncode attribute.
  42     ret = call(*popenargs, **kwargs)
  43
  44     The arguments are the same as for the Popen constructor.  Example:
  45
  46     check_call(["ls", "-l"])
  47     """
  48     retcode = sp.call(*popenargs, **kwargs)
  49     cmd = kwargs.get("args")
  50     if cmd is None:
  51         cmd = popenargs[0]
  52     if retcode:
  53         raise sp.CalledProcessError(retcode, cmd)
  54     return retcode
  55 sp.check_call = check_call
  56 #}}}
  57
  58 #{{{ Excepciones
  59
  60 class CalledProcessError(Exception): #{{{ XXX Python 2.5 forward-compatibility
  61     """This exception is raised when a process run by check_call() returns
  62     a non-zero exit status.  The exit status will be stored in the
  63     returncode attribute."""
  64     def __init__(self, returncode, cmd):
  65         self.returncode = returncode
  66         self.cmd = cmd
  67     def __str__(self):
  68         return ("Command '%s' returned non-zero exit status %d"
  69             % (self.cmd, self.returncode))
  70 sp.CalledProcessError = CalledProcessError
  71 #}}}
  72
  73 class Error(StandardError): pass
  74
  75 class ExecutionFailure(Error, RuntimeError): pass
  76
  77 class RsyncError(Error, EnvironmentError): pass
  78
  79 #}}}
  80
  81 def unzip(bytes, default_dst='.', specific_dst=dict()): # {{{
  82     """Descomprime un buffer de datos en formato ZIP.
  83     Los archivos se descomprimen en default_dst a menos que exista una entrada
  84     en specific_dst cuya clave sea el nombre de archivo a descomprimir, en
  85     cuyo caso, se descomprime usando como destino el valor de dicha clave.
  86     """
  87     log.debug(_(u'Intentando descomprimir'))
  88     if bytes is None:
  89         return
  90     zfile = ZipFile(StringIO(bytes), 'r')
  91     for f in zfile.namelist():
  92         dst = join(specific_dst.get(f, default_dst), f)
  93         if f.endswith(os.sep):
  94             log.debug(_(u'Creando directorio "%s" en "%s"'), f, dst)
  95             os.mkdir(dst)
  96         else:
  97             log.debug(_(u'Descomprimiendo archivo "%s" en "%s"'), f, dst)
  98             file(dst, 'w').write(zfile.read(f))
  99     zfile.close()
 100 #}}}
 101
 102 class SecureProcess(object): #{{{
 103     default = dict(
 104         max_tiempo_cpu      = 120,
 105         max_memoria         = 16,
 106         max_tam_archivo     = 5,
 107         max_cant_archivos   = 5,
 108         max_cant_procesos   = 0,
 109         max_locks_memoria   = 0,
 110     )
 111     uid = config.get('sercom.tester.chroot.user', 65534)
 112     MB = 1048576
 113     # XXX probar! make de un solo archivo lleva nproc=100 y nofile=15
 114     def __init__(self, comando, chroot, cwd, close_stdin=False,
 115                  close_stdout=False, close_stderr=False):
 116         self.comando = comando
 117         self.chroot = chroot
 118         self.cwd = cwd
 119         self.close_stdin = close_stdin
 120         self.close_stdout = close_stdout
 121         self.close_stderr = close_stderr
 122         log.debug('Proceso segurizado: chroot=%s, cwd=%s, user=%s, cpu=%s, '
 123             'as=%sMiB, fsize=%sMiB, nofile=%s, nproc=%s, memlock=%s',
 124             self.chroot, self.cwd, self.uid, self.max_tiempo_cpu,
 125             self.max_memoria, self.max_tam_archivo, self.max_cant_archivos,
 126             self.max_cant_procesos, self.max_locks_memoria)
 127     def __getattr__(self, name):
 128         if getattr(self.comando, name) is not None:
 129             return getattr(self.comando, name)
 130         return config.get('sercom.tester.limits.' + name, self.default[name])
 131     def __call__(self):
 132         x2 = lambda x: (x, x)
 133         if self.close_stdin:
 134             os.close(0)
 135         if self.close_stdout:
 136             os.close(1)
 137         if self.close_stderr:
 138             os.close(2)
 139         os.chroot(self.chroot)
 140         os.chdir(self.cwd)
 141         uinfo = UserInfo(self.uid)
 142         os.setgid(uinfo.gid)
 143         os.setuid(uinfo.uid) # Somos mortales irreversiblemente
 144         rsrc.setrlimit(rsrc.RLIMIT_CPU, x2(self.max_tiempo_cpu))
 145         rsrc.setrlimit(rsrc.RLIMIT_AS, x2(self.max_memoria*self.MB))
 146         rsrc.setrlimit(rsrc.RLIMIT_FSIZE, x2(self.max_tam_archivo*self.MB)) # XXX calcular en base a archivos esperados?
 147         rsrc.setrlimit(rsrc.RLIMIT_NOFILE, x2(self.max_cant_archivos)) #XXX Obtener de archivos esperados?
 148         rsrc.setrlimit(rsrc.RLIMIT_NPROC, x2(self.max_cant_procesos))
 149         rsrc.setrlimit(rsrc.RLIMIT_MEMLOCK, x2(self.max_locks_memoria))
 150         rsrc.setrlimit(rsrc.RLIMIT_CORE, x2(0))
 151         # Tratamos de forzar un sync para que entre al sleep del padre FIXME
 152         import time
 153         time.sleep(0)
 154 #}}}
 155
 156 class Tester(object): #{{{
 157
 158     def __init__(self, name, path, home, queue): #{{{ y properties
 159         self.name = name
 160         self.path = path
 161         self.home = home
 162         self.queue = queue
 163         # Ahora somos mortales (oid mortales)
 164         log.debug(_(u'Cambiando usuario y grupo efectivos a %s:%s (%s:%s)'),
 165             user_info.user, user_info.group, user_info.uid, user_info.gid)
 166         os.setegid(user_info.gid)
 167         os.seteuid(user_info.uid)
 168
 169     @property
 170     def build_path(self):
 171         return join(self.chroot, self.home, 'build')
 172
 173     @property
 174     def test_path(self):
 175         return join(self.chroot, self.home, 'test')
 176
 177     @property
 178     def chroot(self):
 179         return join(self.path, 'chroot_' + self.name)
 180
 181     @property
 182     def orig_chroot(self):
 183         return join(self.path, 'chroot')
 184     #}}}
 185
 186     def run(self): #{{{
 187         entrega_id = self.queue.get() # blocking
 188         while entrega_id is not None:
 189             entrega = Entrega.get(entrega_id)
 190             log.debug(_(u'Nueva entrega para probar en tester %s: %s'),
 191                 self.name, entrega)
 192             self.test(entrega)
 193             log.debug(_(u'Fin de pruebas de: %s'), entrega)
 194             entrega_id = self.queue.get() # blocking
 195     #}}}
 196
 197     def test(self, entrega): #{{{
 198         log.debug(_(u'Tester.test(entrega=%s)'), entrega)
 199         entrega.inicio_tareas = datetime.now()
 200         try:
 201             try:
 202                 self.setup_chroot(entrega)
 203                 self.ejecutar_tareas_fuente(entrega)
 204                 self.ejecutar_tareas_prueba(entrega)
 205                 self.clean_chroot(entrega)
 206             except ExecutionFailure, e:
 207                 entrega.correcta = False
 208                 log.info(_(u'Entrega incorrecta: %s'), entrega)
 209             except Exception, e:
 210                 if isinstance(e, SystemExit): raise
 211                 entrega.observaciones += error_interno
 212                 log.exception(_(u'Hubo una excepción inesperada: %s'), e)
 213             except:
 214                 entrega.observaciones += error_interno
 215                 log.exception(_(u'Hubo una excepción inesperada desconocida'))
 216             else:
 217                 entrega.correcta = True
 218                 log.debug(_(u'Entrega correcta: %s'), entrega)
 219         finally:
 220             entrega.fin_tareas = datetime.now()
 221     #}}}
 222
 223     def setup_chroot(self, entrega): #{{{ y clean_chroot()
 224         log.debug(_(u'Tester.setup_chroot(entrega=%s)'), entrega.shortrepr())
 225         rsync = ('rsync', '--stats', '--itemize-changes', '--human-readable',
 226             '--archive', '--acls', '--delete-during', '--force', # TODO config
 227             join(self.orig_chroot, ''), self.chroot)
 228         log.debug(_(u'Ejecutando como root: %s'), ' '.join(rsync))
 229         os.seteuid(0) # Dios! (para chroot)
 230         os.setegid(0)
 231         try:
 232             sp.check_call(rsync)
 233         finally:
 234             log.debug(_(u'Cambiando usuario y grupo efectivos a %s:%s (%s:%s)'),
 235                 user_info.user, user_info.group, user_info.uid, user_info.gid)
 236             os.setegid(user_info.gid) # Mortal de nuevo
 237             os.seteuid(user_info.uid)
 238         unzip(entrega.archivos, self.build_path)
 239
 240     def clean_chroot(self, entrega):
 241         log.debug(_(u'Tester.clean_chroot(entrega=%s)'), entrega.shortrepr())
 242         pass # Se limpia con el próximo rsync
 243     #}}}
 244
 245     def ejecutar_tareas_fuente(self, entrega): #{{{ y tareas_prueba
 246         log.debug(_(u'Tester.ejecutar_tareas_fuente(entrega=%s)'),
 247             entrega.shortrepr())
 248         tareas = [t for t in entrega.instancia.ejercicio.enunciado.tareas
 249                     if isinstance(t, TareaFuente)]
 250         for tarea in tareas:
 251             tarea.ejecutar(self.build_path, entrega)
 252
 253     def ejecutar_tareas_prueba(self, entrega):
 254         log.debug(_(u'Tester.ejecutar_tareas_prueba(entrega=%s)'),
 255             entrega.shortrepr())
 256         for caso in entrega.instancia.ejercicio.enunciado.casos_de_prueba:
 257             caso.ejecutar(self.test_path, entrega)
 258     #}}}
 259
 260 #}}}
 261
 262 def ejecutar_caso_de_prueba(self, path, entrega): #{{{
 263     log.debug(_(u'CasoDePrueba.ejecutar(path=%s, entrega=%s)'), path,
 264         entrega.shortrepr())
 265     tareas = [t for t in entrega.instancia.ejercicio.enunciado.tareas
 266                 if isinstance(t, TareaPrueba)]
 267     prueba = entrega.add_prueba(self)
 268     try:
 269         try:
 270             for tarea in tareas:
 271                 tarea.ejecutar(path, prueba)
 272         except ExecutionFailure, e:
 273             prueba.exito = False
 274             if self.rechazar_si_falla:
 275                 entrega.exito = False
 276             if self.terminar_si_falla:
 277                 raise ExecutionError(e.comando, e.tarea, prueba)
 278         else:
 279             prueba.exito = True
 280     finally:
 281         prueba.fin = datetime.now()
 282 CasoDePrueba.ejecutar = ejecutar_caso_de_prueba
 283 #}}}
 284
 285 def ejecutar_tarea_fuente(self, path, entrega): #{{{
 286     log.debug(_(u'TareaFuente.ejecutar(path=%s, entrega=%s)'), path,
 287         entrega.shortrepr())
 288     try:
 289         for cmd in self.comandos:
 290             cmd.ejecutar(path, entrega)
 291     except ExecutionFailure, e:
 292         if self.rechazar_si_falla:
 293             entrega.exito = False
 294         if self.terminar_si_falla:
 295             raise ExecutionError(e.comando, tarea)
 296 TareaFuente.ejecutar = ejecutar_tarea_fuente
 297 #}}}
 298
 299 def ejecutar_tarea_prueba(self, path, prueba): #{{{
 300     log.debug(_(u'TareaPrueba.ejecutar(path=%s, prueba=%s)'), path,
 301         prueba.shortrepr())
 302     try:
 303         for cmd in self.comandos:
 304             cmd.ejecutar(path, prueba)
 305     except ExecutionFailure, e:
 306         if self.rechazar_si_falla:
 307             prueba.exito = False
 308         if self.terminar_si_falla:
 309             raise ExecutionError(e.comando, tarea)
 310 TareaPrueba.ejecutar = ejecutar_tarea_prueba
 311 #}}}
 312
 313 def ejecutar_comando_fuente(self, path, entrega): #{{{
 314     log.debug(_(u'ComandoFuente.ejecutar(path=%s, entrega=%s)'), path,
 315         entrega.shortrepr())
 316     comando_ejecutado = entrega.add_comando_ejecutado(self)
 317     unzip(self.archivos_entrada, path, # TODO try/except
 318         dict(__stdin__='/tmp/sercom.tester.%s.stdin' % comando_ejecutado.id)) # TODO /var/run/sercom
 319     options = dict(
 320         close_fds=True,
 321         shell=True,
 322         preexec_fn=SecureProcess(self, 'var/chroot_pepe', '/home/sercom/build')
 323     )
 324     if os.path.exists('/tmp/sercom.tester.%s.stdin' % comando_ejecutado.id): # TODO
 325         options['stdin'] = file('/tmp/sercom.tester.%s.stdin' % comando_ejecutado.id, 'r') # TODO
 326     else:
 327         options['preexec_fn'].close_stdin = True
 328     if self.guardar_stdouterr:
 329         options['stdout'] = file('/tmp/sercom.tester.%s.stdouterr'
 330             % comando_ejecutado.id, 'w') #TODO /var/run/sercom?
 331         options['stderr'] = sp.STDOUT
 332     else:
 333         if self.guardar_stdout:
 334             options['stdout'] = file('/tmp/sercom.tester.%s.stdout'
 335                 % comando_ejecutado.id, 'w') #TODO /run/lib/sercom?
 336         else:
 337             options['preexec_fn'].close_stdout = True
 338         if self.guardar_stderr:
 339             options['stderr'] = file('/tmp/sercom.tester.%s.stderr'
 340                 % comando_ejecutado.id, 'w') #TODO /var/run/sercom?
 341         else:
 342             options['preexec_fn'].close_stderr = True
 343     log.debug(_(u'Ejecutando como root: %s'), self.comando)
 344     os.seteuid(0) # Dios! (para chroot)
 345     os.setegid(0)
 346     try:
 347         try:
 348             proc = sp.Popen(self.comando, **options)
 349         finally:
 350             log.debug(_(u'Cambiando usuario y grupo efectivos a %s:%s (%s:%s)'),
 351                 user_info.user, user_info.group, user_info.uid, user_info.gid)
 352             os.setegid(user_info.gid) # Mortal de nuevo
 353             os.seteuid(user_info.uid)
 354     except Exception, e:
 355         if hasattr(e, 'child_traceback'):
 356             log.error(_(u'Error en el hijo: %s'), e.child_traceback)
 357         raise
 358     proc.wait() #TODO un sleep grande nos caga todo, ver sercom viejo
 359     comando_ejecutado.fin = datetime.now()
 360     buffer = StringIO()
 361     zip = ZipFile(buffer, 'w')
 362     if self.guardar_stdouterr:
 363         zip.write('/tmp/sercom.tester.%s.stdouterr'
 364             % comando_ejecutado.id, '__stdouterr__')
 365     else:
 366         if self.guardar_stdout:
 367             azipwrite('/tmp/sercom.tester.%s.stdout'
 368                 % comando_ejecutado.id, '__stdout__')
 369         if self.guardar_stderr:
 370             zip.write('/tmp/sercom.tester.%s.stderr'
 371                 % comando_ejecutado.id, '__stderr__')
 372     zip.close()
 373     comando_ejecutado.archivos_guardados = buffer.getvalue()
 374
 375 #    if no_anda_ejecucion: # TODO
 376 #        comando_ejecutado.exito = False
 377 #        comando_ejecutado.observaciones += 'No anduvo xxx' # TODO mas info
 378 #        if self.rechazar_si_falla:
 379 #            entrega.exito = False
 380 #        if self.terminar_si_falla: # TODO
 381 #            raise ExecutionFailure(self)
 382     # XXX ESTO EN REALIDAD EN COMANDOS FUENTE NO IRIA
 383     # XXX SOLO HABRÍA QUE CAPTURAR stdout/stderr
 384     # XXX PODRIA TENER ARCHIVOS DE SALIDA PERO SOLO PARA MOSTRAR COMO RESULTADO
 385 #    for archivo in self.archivos_salida:
 386 #        pass # TODO hacer diff
 387 #    if archivos_mal: # TODO
 388 #        comando_ejecutado.exito = False
 389 #        comando_ejecutado.observaciones += 'No anduvo xxx' # TODO mas info
 390 #        if self.rechazar_si_falla:
 391 #            entrega.exito = False
 392 #        if self.terminar_si_falla: # TODO
 393 #            raise ExecutionFailure(self)
 394 #    else:
 395 #        comando_ejecutado.exito = True
 396 #        comando_ejecutado.observaciones += 'xxx OK' # TODO
 397     comando_ejecutado.exito = True
 398     comando_ejecutado.observaciones += 'xxx OK' # TODO
 399 ComandoFuente.ejecutar = ejecutar_comando_fuente
 400 #}}}
 401
 402 def ejecutar_comando_prueba(self, path, prueba): #{{{
 403     log.debug(_(u'ComandoPrueba.ejecutar(path=%s, prueba=%s)'), path,
 404         prueba.shortrepr())
 405     rmtree(path)
 406     os.mkdir(path)
 407     unzip(prueba.caso_de_prueba.archivos_entrada, path) # TODO try/except
 408     unzip(self.archivos_entrada, path) # TODO try/except
 409     comando_ejecutado = prueba.add_comando_ejecutado(self)
 410     # TODO ejecutar en chroot (path)
 411     comando_ejecutado.fin = datetime.now()
 412 #    if no_anda_ejecucion: # TODO
 413 #        comando_ejecutado.exito = False
 414 #        comando_ejecutado.observaciones += 'No anduvo xxx' # TODO
 415 #        if self.rechazar_si_falla:
 416 #            entrega.exito = False
 417 #        if self.terminar_si_falla: # TODO
 418 #            raise ExecutionFailure(self) # TODO info de error
 419 #    for archivo in self.archivos_salida:
 420 #        pass # TODO hacer diff
 421 #    if archivos_mal: # TODO
 422 #        comando_ejecutado.exito = False
 423 #        comando_ejecutado.observaciones += 'No anduvo xxx' # TODO
 424 #        if self.rechazar_si_falla:
 425 #            entrega.exito = False
 426 #        if self.terminar_si_falla: # TODO
 427 #            raise ExecutionFailure(comando=self) # TODO info de error
 428 #    else:
 429 #        comando_ejecutado.exito = True
 430 #        comando_ejecutado.observaciones += 'xxx OK' # TODO
 431     comando_ejecutado.exito = True
 432     comando_ejecutado.observaciones += 'xxx OK' # TODO
 433 ComandoPrueba.ejecutar = ejecutar_comando_prueba
 434 #}}}
 435