1 # vim: set et sw=4 sts=4 encoding=utf-8 foldmethod=marker:
3 from sercom.model import Entrega, CasoDePrueba
4 from sercom.model import TareaFuente, TareaPrueba, ComandoFuente, ComandoPrueba
5 from difflib import unified_diff, HtmlDiff
6 from zipfile import ZipFile, BadZipfile
7 from cStringIO import StringIO
8 from shutil import rmtree
9 from datetime import datetime
10 from os.path import join
11 from turbogears import config
12 import subprocess as sp
13 import resource as rsrc
14 import os, sys, pwd, grp
17 log = logging.getLogger('sercom.tester')
19 error_interno = _(u'\n**Error interno al preparar la entrega.**')
21 class UserInfo(object): #{{{
22 def __init__(self, user):
24 info = pwd.getpwnam(user)
26 info = pwd.get(int(user))
33 self.group = grp.getgrgid(self.gid)[0]
36 user_info = UserInfo(config.get('sercom.tester.user', 65534))
38 def check_call(*popenargs, **kwargs): #{{{ XXX Python 2.5 forward-compatibility
39 """Run command with arguments. Wait for command to complete. If
40 the exit code was zero then return, otherwise raise
41 CalledProcessError. The CalledProcessError object will have the
42 return code in the returncode attribute.
43 ret = call(*popenargs, **kwargs)
45 The arguments are the same as for the Popen constructor. Example:
47 check_call(["ls", "-l"])
49 retcode = sp.call(*popenargs, **kwargs)
50 cmd = kwargs.get("args")
54 raise sp.CalledProcessError(retcode, cmd)
56 sp.check_call = check_call
61 class CalledProcessError(Exception): #{{{ XXX Python 2.5 forward-compatibility
62 """This exception is raised when a process run by check_call() returns
63 a non-zero exit status. The exit status will be stored in the
64 returncode attribute."""
65 def __init__(self, returncode, cmd):
66 self.returncode = returncode
69 return ("Command '%s' returned non-zero exit status %d"
70 % (self.cmd, self.returncode))
71 sp.CalledProcessError = CalledProcessError
74 class Error(StandardError): pass
76 class ExecutionFailure(Error, RuntimeError): #{{{
77 def __init__(self, comando, tarea=None, caso_de_prueba=None):
78 self.comando = comando
80 self.caso_de_prueba = caso_de_prueba
85 def unzip(bytes, default_dst='.', specific_dst=dict()): # {{{
86 u"""Descomprime un buffer de datos en formato ZIP.
87 Los archivos se descomprimen en default_dst a menos que exista una entrada
88 en specific_dst cuya clave sea el nombre de archivo a descomprimir, en
89 cuyo caso, se descomprime usando como destino el valor de dicha clave.
91 log.debug(_(u'Intentando descomprimir'))
94 zfile = ZipFile(StringIO(bytes), 'r')
95 for f in zfile.namelist():
96 dst = join(specific_dst.get(f, default_dst), f)
97 if f.endswith(os.sep):
98 log.debug(_(u'Creando directorio "%s" en "%s"'), f, dst)
101 log.debug(_(u'Descomprimiendo archivo "%s" en "%s"'), f, dst)
102 file(dst, 'w').write(zfile.read(f))
106 class SecureProcess(object): #{{{
108 max_tiempo_cpu = 120,
111 max_cant_archivos = 5,
112 max_cant_procesos = 0,
113 max_locks_memoria = 0,
115 uid = config.get('sercom.tester.chroot.user', 65534)
117 # XXX probar! make de un solo archivo lleva nproc=100 y nofile=15
118 def __init__(self, comando, chroot, cwd, close_stdin=False,
119 close_stdout=False, close_stderr=False):
120 self.comando = comando
123 self.close_stdin = close_stdin
124 self.close_stdout = close_stdout
125 self.close_stderr = close_stderr
126 log.debug(_(u'Proceso segurizado: chroot=%s, cwd=%s, user=%s, cpu=%s, '
127 u'as=%sMiB, fsize=%sMiB, nofile=%s, nproc=%s, memlock=%s'),
128 self.chroot, self.cwd, self.uid, self.max_tiempo_cpu,
129 self.max_memoria, self.max_tam_archivo, self.max_cant_archivos,
130 self.max_cant_procesos, self.max_locks_memoria)
131 def __getattr__(self, name):
132 if getattr(self.comando, name) is not None:
133 return getattr(self.comando, name)
134 return config.get('sercom.tester.limits.' + name, self.default[name])
136 x2 = lambda x: (x, x)
139 if self.close_stdout:
141 if self.close_stderr:
143 os.chroot(self.chroot)
145 uinfo = UserInfo(self.uid)
147 os.setuid(uinfo.uid) # Somos mortales irreversiblemente
148 rsrc.setrlimit(rsrc.RLIMIT_CPU, x2(self.max_tiempo_cpu))
149 rsrc.setrlimit(rsrc.RLIMIT_AS, x2(self.max_memoria*self.MB))
150 rsrc.setrlimit(rsrc.RLIMIT_FSIZE, x2(self.max_tam_archivo*self.MB)) # XXX calcular en base a archivos esperados?
151 rsrc.setrlimit(rsrc.RLIMIT_NOFILE, x2(self.max_cant_archivos)) #XXX Obtener de archivos esperados?
152 rsrc.setrlimit(rsrc.RLIMIT_NPROC, x2(self.max_cant_procesos))
153 rsrc.setrlimit(rsrc.RLIMIT_MEMLOCK, x2(self.max_locks_memoria))
154 rsrc.setrlimit(rsrc.RLIMIT_CORE, x2(0))
155 # Tratamos de forzar un sync para que entre al sleep del padre FIXME
160 class Tester(object): #{{{
162 def __init__(self, name, path, home, queue): #{{{ y properties
167 # Ahora somos mortales (oid mortales)
168 os.setegid(user_info.gid)
169 os.seteuid(user_info.uid)
170 log.debug(_(u'usuario y grupo efectivos cambiados a %s:%s (%s:%s)'),
171 user_info.user, user_info.group, user_info.uid, user_info.gid)
174 def build_path(self):
175 return join(self.chroot, self.home, 'build')
179 return join(self.chroot, self.home, 'test')
183 return join(self.path, 'chroot_' + self.name)
186 def orig_chroot(self):
187 return join(self.path, 'chroot')
191 entrega_id = self.queue.get() # blocking
192 while entrega_id is not None:
193 entrega = Entrega.get(entrega_id)
194 log.debug(_(u'Nueva entrega para probar en tester %s: %s'),
197 log.debug(_(u'Fin de pruebas de: %s'), entrega)
198 entrega_id = self.queue.get() # blocking
201 def test(self, entrega): #{{{
202 log.debug(_(u'Tester.test(entrega=%s)'), entrega)
203 entrega.inicio = datetime.now()
206 self.setup_chroot(entrega)
207 self.ejecutar_tareas_fuente(entrega)
208 self.ejecutar_tareas_prueba(entrega)
209 self.clean_chroot(entrega)
210 except ExecutionFailure, e:
211 entrega.exito = False
212 log.info(_(u'Entrega incorrecta: %s'), entrega)
214 if isinstance(e, SystemExit): raise
215 entrega.observaciones += error_interno
216 log.exception(_('Hubo una excepcion inesperada')) # FIXME encoding
218 entrega.observaciones += error_interno
219 log.exception(_('Hubo una excepcion inesperada desconocida')) # FIXME encoding
222 log.debug(_(u'Entrega correcta: %s'), entrega)
224 entrega.fin = datetime.now()
227 def setup_chroot(self, entrega): #{{{ y clean_chroot()
228 log.debug(_(u'Tester.setup_chroot(entrega=%s)'), entrega.shortrepr())
229 rsync = ('rsync', '--stats', '--itemize-changes', '--human-readable',
230 '--archive', '--acls', '--delete-during', '--force', # TODO config
231 join(self.orig_chroot, ''), self.chroot)
232 log.debug(_(u'Ejecutando como root: %s'), ' '.join(rsync))
233 os.seteuid(0) # Dios! (para chroot)
238 os.setegid(user_info.gid) # Mortal de nuevo
239 os.seteuid(user_info.uid)
240 log.debug(_(u'Usuario y grupo efectivos cambiados a %s:%s (%s:%s)'),
241 user_info.user, user_info.group, user_info.uid, user_info.gid)
242 unzip(entrega.archivos, self.build_path)
244 def clean_chroot(self, entrega):
245 log.debug(_(u'Tester.clean_chroot(entrega=%s)'), entrega.shortrepr())
246 pass # Se limpia con el próximo rsync
249 def ejecutar_tareas_fuente(self, entrega): #{{{ y tareas_prueba
250 log.debug(_(u'Tester.ejecutar_tareas_fuente(entrega=%s)'),
252 tareas = [t for t in entrega.instancia.ejercicio.enunciado.tareas
253 if isinstance(t, TareaFuente)]
255 tarea.ejecutar(self.build_path, entrega)
257 def ejecutar_tareas_prueba(self, entrega):
258 log.debug(_(u'Tester.ejecutar_tareas_prueba(entrega=%s)'),
260 for caso in entrega.instancia.ejercicio.enunciado.casos_de_prueba:
261 caso.ejecutar(self.test_path, entrega)
266 def ejecutar_caso_de_prueba(self, path, entrega): #{{{
267 log.debug(_(u'CasoDePrueba.ejecutar(path=%s, entrega=%s)'), path,
269 tareas = [t for t in entrega.instancia.ejercicio.enunciado.tareas
270 if isinstance(t, TareaPrueba)]
271 prueba = entrega.add_prueba(self)
275 tarea.ejecutar(path, prueba)
276 except ExecutionFailure, e:
278 if self.rechazar_si_falla:
279 entrega.exito = False
280 if self.terminar_si_falla:
281 raise ExecutionFailure(e.comando, e.tarea, self)
285 prueba.fin = datetime.now()
286 CasoDePrueba.ejecutar = ejecutar_caso_de_prueba
289 def ejecutar_tarea_fuente(self, path, entrega): #{{{
290 log.debug(_(u'TareaFuente.ejecutar(path=%s, entrega=%s)'), path,
293 for cmd in self.comandos:
294 cmd.ejecutar(path, entrega)
295 except ExecutionFailure, e:
296 if self.rechazar_si_falla:
297 entrega.exito = False
298 if self.terminar_si_falla:
299 raise ExecutionFailure(e.comando, self)
300 TareaFuente.ejecutar = ejecutar_tarea_fuente
303 def ejecutar_tarea_prueba(self, path, prueba): #{{{
304 log.debug(_(u'TareaPrueba.ejecutar(path=%s, prueba=%s)'), path,
307 for cmd in self.comandos:
308 cmd.ejecutar(path, prueba)
309 except ExecutionFailure, e:
310 if self.rechazar_si_falla:
312 if self.terminar_si_falla:
313 raise ExecutionFailure(e.comando, self)
314 TareaPrueba.ejecutar = ejecutar_tarea_prueba
317 def ejecutar_comando_fuente(self, path, entrega): #{{{
318 log.debug(_(u'ComandoFuente.ejecutar(path=%s, entrega=%s)'), path,
320 comando_ejecutado = entrega.add_comando_ejecutado(self) # TODO debería rodear solo la ejecución del comando
321 basetmp = '/tmp/sercom.tester.fuente' # FIXME TODO /var/run/sercom?
322 unzip(self.archivos_entrada, path, # TODO try/except
323 {self.STDIN: '%s.%s.stdin' % (basetmp, comando_ejecutado.id)})
327 preexec_fn=SecureProcess(self, 'var/chroot_pepe', '/home/sercom/build')
329 if os.path.exists('%s.%s.stdin' % (basetmp, comando_ejecutado.id)):
330 options['stdin'] = file('%s.%s.stdin' % (basetmp, comando_ejecutado.id),
333 options['preexec_fn'].close_stdin = True
334 a_guardar = set(self.archivos_a_guardar)
335 if self.archivos_a_comparar:
336 zip_a_comparar = ZipFile(StringIO(self.archivos_a_comparar), 'r')
337 a_comparar = set(zip_a_comparar.namelist())
339 zip_a_comparar = None
340 a_comparar = frozenset()
341 a_usar = frozenset(a_guardar | a_comparar)
342 if self.STDOUTERR in a_usar:
343 options['stdout'] = file('%s.%s.stdouterr' % (basetmp,
344 comando_ejecutado.id), 'w')
345 options['stderr'] = sp.STDOUT
347 if self.STDOUT in a_usar:
348 options['stdout'] = file('%s.%s.stdout' % (basetmp,
349 comando_ejecutado.id), 'w')
351 options['preexec_fn'].close_stdout = True
352 if self.STDERR in a_usar:
353 options['stderr'] = file('%s.%s.stderr' % (basetmp,
354 comando_ejecutado.id), 'w')
356 options['preexec_fn'].close_stderr = True
357 log.debug(_(u'Ejecutando como root: %s'), self.comando)
358 os.seteuid(0) # Dios! (para chroot)
362 proc = sp.Popen(self.comando, **options)
364 os.setegid(user_info.gid) # Mortal de nuevo
365 os.seteuid(user_info.uid)
366 log.debug(_(u'Usuario y grupo efectivos cambiados a %s:%s (%s:%s)'),
367 user_info.user, user_info.group, user_info.uid, user_info.gid)
369 if hasattr(e, 'child_traceback'):
370 log.error(_(u'Error en el hijo: %s'), e.child_traceback)
372 proc.wait() #TODO un sleep grande nos caga todo, ver sercom viejo
373 comando_ejecutado.fin = datetime.now() # TODO debería rodear solo la ejecución del comando
374 if self.retorno != self.RET_ANY:
375 if self.retorno == self.RET_FAIL:
376 if proc.returncode == 0:
377 if self.rechazar_si_falla:
378 entrega.exito = False
379 comando_ejecutado.exito = False
380 comando_ejecutado.observaciones += _(u'Se esperaba que el '
381 u'programa termine con un error (código de retorno '
382 u'distinto de 0) pero terminó bien (código de retorno '
384 log.debug(_(u'Se esperaba que el programa termine '
385 u'con un error (código de retorno distinto de 0) pero '
386 u'terminó bien (código de retorno 0).\n'))
387 elif self.retorno != proc.returncode:
388 if self.rechazar_si_falla:
389 entrega.exito = False
390 comando_ejecutado.exito = False
391 if proc.returncode < 0:
392 comando_ejecutado.observaciones += _(u'Se esperaba terminar '
393 u'con un código de retorno %s pero se obtuvo una señal %s '
394 u'(%s).\n') % (self.retorno, -proc.returncode,
395 -proc.returncode) # TODO poner con texto
396 log.debug(_(u'Se esperaba terminar con un código '
397 u'de retorno %s pero se obtuvo una señal %s (%s).\n'),
398 self.retorno, -proc.returncode, -proc.returncode)
400 comando_ejecutado.observaciones += _(u'Se esperaba terminar '
401 u'con un código de retorno %s pero se obtuvo %s.\n') \
402 % (self.retorno, proc.returncode)
403 log.debug(_(u'Se esperaba terminar con un código de retorno '
404 u'%s pero se obtuvo %s.\n'), self.retorno, proc.returncode)
405 if comando_ejecutado.exito is None:
406 log.debug(_(u'Código de retorno OK'))
409 zip = ZipFile(buffer, 'w')
410 # Guardamos stdout/stderr
411 if self.STDOUTERR in a_guardar:
412 a_guardar.remove(self.STDOUTERR)
413 zip.write('%s.%s.stdouterr' % (basetmp, comando_ejecutado.id),
416 if self.STDOUT in a_guardar:
417 a_guardar.remove(self.STDOUT)
418 zip.write('%s.%s.stdout' % (basetmp, comando_ejecutado.id),
420 if self.STDERR in a_guardar:
421 a_guardar.remove(self.STDERR)
422 zip.write('%s.%s.stderr' % (basetmp, comando_ejecutado.id),
426 if not os.path.exists(join(path, f)):
427 if self.rechazar_si_falla:
428 entrega.exito = False
429 comando_ejecutado.exito = False
430 comando_ejecutado.observaciones += _(u'Se esperaba un archivo '
431 u'"%s" para guardar pero no fue encontrado.\n') % f
432 log.debug(_(u'Se esperaba un archivo "%s" para guardar pero '
433 u'no fue encontrado'), f)
435 zip.write(join(path, f), f)
437 comando_ejecutado.archivos = buffer.getvalue()
438 def diff(new, zip_in, zip_out, name, longname=None, origname='correcto',
439 newname='entregado'):
442 new = file(new, 'r').readlines()
443 orig = zip_in.read(name).split('\n')
444 udiff = ''.join(list(unified_diff(orig, new, fromfile=name+'.'+origname,
445 tofile=name+'.'+newname)))
447 if self.rechazar_si_falla:
448 entrega.exito = False
449 comando_ejecutado.exito = False
450 comando_ejecutado.observaciones += _(u'%s no coincide con lo '
451 u'esperado (archivo "%s.diff").\n') % (longname, name)
452 log.debug(_(u'%s no coincide con lo esperado (archivo "%s.diff")'),
454 htmldiff = HtmlDiff().make_file(orig, new,
455 fromdesc=name+'.'+origname, todesc=name+'.'+newname,
456 context=True, numlines=3)
457 zip_out.writestr(name + '.diff', udiff)
458 zip_out.writestr(name + '.diff.html', htmldiff)
464 zip = ZipFile(buffer, 'w')
465 # Comparamos stdout/stderr
466 if self.STDOUTERR in a_comparar:
467 a_comparar.remove(self.STDOUTERR)
468 diff('%s.%s.stdouterr' % (basetmp, comando_ejecutado.id),
469 zip_a_comparar, zip, self.STDOUTERR,
470 _(u'La salida estándar y de error combinada'))
472 if self.STDOUT in a_comparar:
473 a_comparar.remove(self.STDOUT)
474 diff('%s.%s.stdout' % (basetmp, comando_ejecutado.id),
475 zip_a_comparar, zip, self.STDOUT, _(u'La salida estándar'))
476 if self.STDERR in a_comparar:
477 a_comparar.remove(self.STDERR)
478 diff('%s.%s.stderr' % (basetmp, comando_ejecutado.id),
479 zip_a_comparar, zip, self.STDERR, _(u'La salida de error'))
482 if not os.path.exists(join(path, f)):
483 if self.rechazar_si_falla:
484 entrega.exito = False
485 comando_ejecutado.exito = False
486 comando_ejecutado.observaciones += _(u'Se esperaba un archivo '
487 u'"%s" para comparar pero no fue encontrado') % f
488 log.debug(_(u'Se esperaba un archivo "%s" para comparar pero '
489 u'no fue encontrado'), f)
491 diff(join(path, f), zip_a_comparar, zip, f)
493 comando_ejecutado.diferencias = buffer.getvalue()
494 if comando_ejecutado.exito is None:
495 comando_ejecutado.exito = True
496 elif self.terminar_si_falla:
497 raise ExecutionFailure(self)
499 ComandoFuente.ejecutar = ejecutar_comando_fuente
502 def ejecutar_comando_prueba(self, path, prueba): #{{{
503 log.debug(_(u'ComandoPrueba.ejecutar(path=%s, prueba=%s)'), path,
507 unzip(prueba.caso_de_prueba.archivos_entrada, path) # TODO try/except
508 unzip(self.archivos_entrada, path) # TODO try/except
509 comando_ejecutado = prueba.add_comando_ejecutado(self)
510 # TODO ejecutar en chroot (path)
511 comando_ejecutado.fin = datetime.now()
512 # if no_anda_ejecucion: # TODO
513 # comando_ejecutado.exito = False
514 # comando_ejecutado.observaciones += 'No anduvo xxx' # TODO
515 # if self.rechazar_si_falla:
516 # entrega.exito = False
517 # if self.terminar_si_falla: # TODO
518 # raise ExecutionFailure(self) # TODO info de error
519 # for archivo in self.archivos_salida:
520 # pass # TODO hacer diff
521 # if archivos_mal: # TODO
522 # comando_ejecutado.exito = False
523 # comando_ejecutado.observaciones += 'No anduvo xxx' # TODO
524 # if self.rechazar_si_falla:
525 # entrega.exito = False
526 # if self.terminar_si_falla: # TODO
527 # raise ExecutionFailure(comando=self) # TODO info de error
529 # comando_ejecutado.exito = True
530 # comando_ejecutado.observaciones += 'xxx OK' # TODO
531 comando_ejecutado.exito = True
532 comando_ejecutado.observaciones += 'xxx OK' # TODO
533 ComandoPrueba.ejecutar = ejecutar_comando_prueba